Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

disable failing h2spec test #296

Merged
merged 1 commit into from
Aug 25, 2022
Merged

Conversation

nickzaev
Copy link
Contributor

After adding tests to h2spec covering Stream ID values, the test that is supposed to ensure that Stream ID values are not reused is failing for about 2 out of 10 times.
This behavior is always reproduced in the same way. After starting Tempesta and running that test for the first time, there will be a trace in dmesg (which is basically the first bullet of tempesta-tech/tempesta#1387):

[Thu Aug 25 17:54:48 2022] ------------[ cut here ]------------
[Thu Aug 25 17:54:48 2022] WARNING: CPU: 0 PID: 228365 at /root/tempesta/fw/http.c:6495 tfw_http_msg_process_generic+0x409/0x670 [tempesta_fw]
[Thu Aug 25 17:54:48 2022] Modules linked in: tempesta_fw(OE) tempesta_db(OE) tempesta_tls(OE) tempesta_lib(OE) sha256_ssse3 sha512_ssse3 dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua input_leds joydev serio_raw mac_hid qemu_fw_cfg sch_fq_codel msr i
p_tables x_tables autofs4 btrfs blake2b_generic zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear hid_generic usbhid hid crct10dif_pclmul crc32_pclmul ghash_clmulni_
intel aesni_intel crypto_simd cryptd glue_helper bochs_drm drm_vram_helper drm_ttm_helper ttm drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops psmouse cec virtio_net net_failover failover drm virtio_scsi i2c_piix4 pata_acpi floppy [last unload
ed: tempesta_lib]
[Thu Aug 25 17:54:48 2022] CPU: 0 PID: 228365 Comm: h2spec Tainted: G        W  OE     5.10.35+ #1
[Thu Aug 25 17:54:48 2022] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.15.0-0-g2dd4b9b3f840-prebuilt.qemu.org 04/01/2014
[Thu Aug 25 17:54:48 2022] RIP: 0010:tfw_http_msg_process_generic+0x409/0x670 [tempesta_fw]
[Thu Aug 25 17:54:48 2022] Code: 98 00 00 00 44 8b 95 70 ff ff ff a8 10 0f 84 72 fd ff ff e9 08 ff ff ff 4c 89 63 10 4d 89 24 24 4d 89 64 24 08 e9 6d fc ff ff <0f> 0b 41 ba ea ff ff ff e9 4e fd ff ff e8 05 89 ff ff 49 89 47 40
[Thu Aug 25 17:54:48 2022] RSP: 0018:ffff97b4c0003a58 EFLAGS: 00010246
[Thu Aug 25 17:54:48 2022] RAX: 0000000000000000 RBX: ffff8a3fd7b20000 RCX: 0000000000000000
[Thu Aug 25 17:54:48 2022] RDX: ffff8a3ff4644a00 RSI: 0000000000000000 RDI: ffff8a3fd7b20000
[Thu Aug 25 17:54:48 2022] RBP: ffff97b4c0003af8 R08: ffff8a3ff4644a00 R09: ffff97b4c0003aa8
[Thu Aug 25 17:54:48 2022] R10: 0000000000000009 R11: 0000000000000000 R12: 0000000000000000
[Thu Aug 25 17:54:48 2022] R13: ffff8a3fd7b206f8 R14: 0000000000000000 R15: 0000000000000000
[Thu Aug 25 17:54:48 2022] FS:  00007fdd54ff4740(0000) GS:ffff8a407bc00000(0000) knlGS:0000000000000000
[Thu Aug 25 17:54:48 2022] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[Thu Aug 25 17:54:48 2022] CR2: 0000000000b3ae04 CR3: 0000000093754000 CR4: 00000000003506f0
[Thu Aug 25 17:54:48 2022] Call Trace:
[Thu Aug 25 17:54:48 2022]  <IRQ>
[Thu Aug 25 17:54:48 2022]  ? ss_skb_chop_head_tail+0xbb/0x1d0 [tempesta_fw]
[Thu Aug 25 17:54:48 2022]  ? ss_skb_process+0xf6/0x140 [tempesta_fw]
[Thu Aug 25 17:54:48 2022]  tfw_h2_frame_process+0x308/0x440 [tempesta_fw]
[Thu Aug 25 17:54:48 2022]  tfw_http_msg_process+0x37/0x40 [tempesta_fw]
[Thu Aug 25 17:54:48 2022]  tfw_connection_recv+0x59/0xa0 [tempesta_fw]
[Thu Aug 25 17:54:48 2022]  tfw_tls_connection_recv+0x19d/0x380 [tempesta_fw]
[Thu Aug 25 17:54:48 2022]  ss_tcp_process_data+0x1e6/0x3f0 [tempesta_fw]
[Thu Aug 25 17:54:48 2022]  ss_tcp_data_ready+0x4e/0x90 [tempesta_fw]
[Thu Aug 25 17:54:48 2022]  tcp_data_ready+0x2b/0xd0
[Thu Aug 25 17:54:48 2022]  tcp_rcv_established+0x5a7/0x670
[Thu Aug 25 17:54:48 2022]  tcp_v4_do_rcv+0x140/0x200
[Thu Aug 25 17:54:48 2022]  tcp_v4_rcv+0xcfd/0xe10
[Thu Aug 25 17:54:48 2022]  ip_protocol_deliver_rcu+0x30/0x1b0
[Thu Aug 25 17:54:48 2022]  ip_local_deliver_finish+0x48/0x60
[Thu Aug 25 17:54:48 2022]  ip_local_deliver+0x72/0x110
[Thu Aug 25 17:54:48 2022]  ? tfw_ipv4_nf_hook+0xce/0x150 [tempesta_fw]
[Thu Aug 25 17:54:48 2022]  ip_rcv_finish+0x87/0xa0
[Thu Aug 25 17:54:48 2022]  ip_rcv+0xcc/0xe0
[Thu Aug 25 17:54:48 2022]  ? ip_rcv_finish_core.isra.0+0x420/0x420
[Thu Aug 25 17:54:48 2022]  __netif_receive_skb_one_core+0x88/0xa0
[Thu Aug 25 17:54:48 2022]  __netif_receive_skb+0x18/0x60
[Thu Aug 25 17:54:48 2022]  process_backlog+0xa9/0x160
[Thu Aug 25 17:54:48 2022]  net_rx_action+0x13e/0x390
[Thu Aug 25 17:54:48 2022]  __do_softirq+0xd9/0x291
[Thu Aug 25 17:54:48 2022]  asm_call_irq_on_stack+0x12/0x20
[Thu Aug 25 17:54:48 2022]  </IRQ>
[Thu Aug 25 17:54:48 2022]  do_softirq_own_stack+0x3d/0x50
[Thu Aug 25 17:54:48 2022]  do_softirq.part.0+0x46/0x50
[Thu Aug 25 17:54:48 2022]  __local_bh_enable_ip+0x50/0x60
[Thu Aug 25 17:54:48 2022]  ip_finish_output2+0x1ab/0x590
[Thu Aug 25 17:54:48 2022]  ? __cgroup_bpf_run_filter_skb+0x3c3/0x3d0
[Thu Aug 25 17:54:48 2022]  __ip_finish_output+0xd8/0x220
[Thu Aug 25 17:54:48 2022]  ip_finish_output+0x2d/0xb0
[Thu Aug 25 17:54:48 2022]  ip_output+0x7a/0x100
[Thu Aug 25 17:54:48 2022]  ip_local_out+0x3d/0x50
[Thu Aug 25 17:54:48 2022]  __ip_queue_xmit+0x17a/0x470
[Thu Aug 25 17:54:48 2022]  ip_queue_xmit+0x15/0x20
[Thu Aug 25 17:54:48 2022]  __tcp_transmit_skb+0xa20/0xbe0
[Thu Aug 25 17:54:48 2022]  tcp_write_xmit+0x453/0x1350
[Thu Aug 25 17:54:48 2022]  __tcp_push_pending_frames+0x37/0x100
[Thu Aug 25 17:54:48 2022]  tcp_push+0xfc/0x100
[Thu Aug 25 17:54:48 2022]  tcp_sendmsg_locked+0xd36/0xe70
[Thu Aug 25 17:54:48 2022]  tcp_sendmsg+0x2d/0x50
[Thu Aug 25 17:54:48 2022]  inet_sendmsg+0x43/0x70
[Thu Aug 25 17:54:48 2022]  sock_sendmsg+0x5e/0x70
[Thu Aug 25 17:54:48 2022]  sock_write_iter+0x93/0xf0
[Thu Aug 25 17:54:48 2022]  new_sync_write+0x192/0x1b0
[Thu Aug 25 17:54:48 2022]  vfs_write+0x185/0x250
[Thu Aug 25 17:54:48 2022]  ksys_write+0xb1/0xe0
[Thu Aug 25 17:54:48 2022]  __x64_sys_write+0x1a/0x20
[Thu Aug 25 17:54:48 2022]  do_syscall_64+0x38/0x90
[Thu Aug 25 17:54:48 2022]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Thu Aug 25 17:54:48 2022] RIP: 0033:0x4a7f20
[Thu Aug 25 17:54:48 2022] Code: 8b 7c 24 10 48 8b 74 24 18 48 8b 54 24 20 49 c7 c2 00 00 00 00 49 c7 c0 00 00 00 00 49 c7 c1 00 00 00 00 48 8b 44 24 08 0f 05 <48> 3d 01 f0 ff ff 76 20 48 c7 44 24 28 ff ff ff ff 48 c7 44 24 30
[Thu Aug 25 17:54:48 2022] RSP: 002b:000000c0000ccd60 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[Thu Aug 25 17:54:48 2022] RAX: ffffffffffffffda RBX: 000000c000034500 RCX: 00000000004a7f20
[Thu Aug 25 17:54:48 2022] RDX: 000000000000002a RSI: 000000c000148000 RDI: 0000000000000003
[Thu Aug 25 17:54:48 2022] RBP: 000000c0000ccdb0 R08: 0000000000000000 R09: 0000000000000000
[Thu Aug 25 17:54:48 2022] R10: 0000000000000000 R11: 0000000000000202 R12: 000000007bfb43c5
[Thu Aug 25 17:54:48 2022] R13: 000000000000000a R14: 0000000000000046 R15: 0000000000000100
[Thu Aug 25 17:54:48 2022] ---[ end trace 65f4a5140a321cc3 ]---

Note that the test always passes (at least I've tried for about 50 times) on the first run, then if we don't restart Tempesta, whenever there's a warning:

[Thu Aug 25 18:01:50 2022] [tempesta tls] Warning: [::ffff:127.0.0.1] Bad TLS alert

the test will fail with the message from h2spec:

Hypertext Transfer Protocol Version 2 (HTTP/2)
  5. Streams and Multiplexing
    5.1. Stream States
      5.1.1. Stream Identifiers
        × 4: Sends stream identifier that has already been used
          -> The endpoint MUST response with a connection error of type PROTOCOL_ERROR.
             Expected: GOAWAY Frame (Error Code: PROTOCOL_ERROR)
                       Connection closed
               Actual: DATA Frame (length:1379, flags:0x01, stream_id:5)

Copy link
Contributor

@krizhanovsky krizhanovsky left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. I added the test to tempesta-tech/tempesta#1387 (comment)

@nickzaev nickzaev merged commit cfc34e5 into master Aug 25, 2022
@nickzaev nickzaev deleted the nz-disable-h2spec-failing-test branch August 25, 2022 18:58
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants