WINSOCKBVT:Test_BVT_Multicast_IPMulticast failing

Hello,

I am in process of writing an out-of-band WFP callout driver and I am having trouble passing the WINSOCKBVT:Test_BVT_Multicast_IPMulticast test. All other BVT tests pass fine including Test_BVT_Multicast_JoinLeaft which is curious . I started with ALE_CONNECT/RECV layers by Pend + absorb + clone and then from other thread Complete and Inject. I figured out its the ALE_AUTH_CONNECT non-reauthrozie path that is causing issues. I tried to remove the absorption/clone part and just keeping Pend/Complete and everything passed. So its definitely caused by absorption/reinjection.

This is the part where I get confused, why is this the only that single case that is failing? Wireshark show that the UDP multicast packet didnt even get to the wire. FwpsInjectTransportSendAsync returned STATUS_SUCCESS and NBL inside the callback also reports STATUS_SUCCESS. I am also not doing anything special with the packet, I checked the inspect sample code and its pretty similar.

Reinjection code:

      FWPS_TRANSPORT_SEND_PARAMS sendArgs{};
      sendArgs.remoteAddress = (UINT8*)(packet->RemoteAddr.byteArray16); // network byte order - first 4 bytes is IpV4
      sendArgs.remoteScopeId = packet->RemoteScopeId;
      sendArgs.controlData = packet->ControlData;
      sendArgs.controlDataLength = packet->ControlDataLen;


      // packet is freed in the callback
      status = ::FwpsInjectTransportSendAsync(gInjectionHandle, nullptr, packet->EndpointHandle, 0, &sendArgs, GetAFByLayer(packet->LayerId), static_cast<COMPARTMENT_ID>(packet->CompartmentId), packet->NetBufferList, InspectCompleteCallback, packet);
      if (!NT_SUCCESS(status)) {
        TraceEvents(TRACE_LEVEL_ERROR, General, "FwpsInjectTransportSendAsync failed with %!STATUS!", status);
        FreePacketInspectQueueEntry(packet);
        return;
      }

Relevant info gathering by the clone part - non-reauthorize ALE_CONNECT before pend/absorb

      if (!FWPS_IS_METADATA_FIELD_PRESENT(inMetaValues, FWPS_METADATA_FIELD_TRANSPORT_ENDPOINT_HANDLE)) {
        TraceEvents(TRACE_LEVEL_FATAL, General, "Missing transport control data!");
        FreePacketInspectQueueEntry(info);
        return nullptr;
      }

      info->EndpointHandle = inMetaValues->transportEndpointHandle;
      info->RemoteScopeId = inMetaValues->remoteScopeId;

      if (FWPS_IS_METADATA_FIELD_PRESENT(inMetaValues, FWPS_METADATA_FIELD_TRANSPORT_CONTROL_DATA)) {
        if (inMetaValues->controlDataLength == 0) {
          TraceEvents(TRACE_LEVEL_FATAL, General, "Invalid control data length!");
          FreePacketInspectQueueEntry(info);
          return nullptr;
        }

        info->ControlData = AllocateBytesWithTag(WSACMSGHDR, inMetaValues->controlDataLength, ::ExDefaultNonPagedPoolType, INSPECT_TAG);
        if (!info->ControlData) {
          FreePacketInspectQueueEntry(info);
          return nullptr;
        }

        info->ControlDataLen = inMetaValues->controlDataLength;
        ::memcpy(info->ControlData, inMetaValues->controlData, info->ControlDataLen);
      }

      if (nbl) { // layerData

        auto status = ::FwpsAllocateCloneNetBufferList(nbl, nullptr, nullptr, 0, &info->NetBufferList);

        if (!NT_SUCCESS(status)) {
          TraceEvents(TRACE_LEVEL_ERROR, General, "Failed cloning NetBufferList %!STATUS!", status);
          FreePacketInspectQueueEntry(info);
          return nullptr;
        }
      }

This is output from the test case:

 Start Case:Winsock API\Current Protocols (IPv4/IPv6)\BVT\IP Multicast:[[IGN-]Tue Nov 25 14:08:58 2025[-IGN]]
 Priority: 0, Owner: joryp
 WSAStartup
 Test_BVT_Multicast_IPMulticast START TIME 11/25/2025 14:8:58

 FNHN_GetProviderSocket created socket (00000000000003DC) for protocol MSAFD Tcpip [UDP/IP]
 FNHN_GetProviderSocket created socket (0000000000000378) for protocol MSAFD Tcpip [UDP/IP]
 Wait timed-out.
 completion: 0 bytes 0x00000103 status
 WINSOCKBVT:Test_BVT_Multicast_IPMulticast: WSARecvFrom failed: 0xc0070005/996 (Overlapped I/O event is not in a signaled state. ) [net\test\winsock\ws\functional\bvt\bvt.cpp@8635] (AF_INET)

Those are the 2 packets that I am seeing with successful test without my driver (the same on different IF)

Frame 6531: Packet, 292 bytes on wire (2336 bits), 292 bytes captured (2336 bits) on interface \Device\NPF_Loopback, id 4
    Section number: 1
    Interface id: 4 (\Device\NPF_Loopback)
    Encapsulation type: NULL/Loopback (15)
    Arrival Time: Nov 25, 2025 13:46:05.255925000 Central Europe Standard Time
    UTC Arrival Time: Nov 25, 2025 12:46:05.255925000 UTC
    Epoch Arrival Time: 1764074765.255925000
    [Time shift for this packet: 0.000000000 seconds]
    [Time delta from previous captured frame: 66.169000 milliseconds]
    [Time since reference or first frame: 1 minute, 19.864088000 seconds]
    Frame Number: 6531
    Frame Length: 292 bytes (2336 bits)
    Capture Length: 292 bytes (2336 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: null:ip:udp:data]
    Character encoding: ASCII (0)
    [Coloring Rule Name: UDP]
    [Coloring Rule String: udp]
Null/Loopback
Internet Protocol Version 4, Src: 192.168.1.161, Dst: 237.221.112.97
User Datagram Protocol, Src Port: 60538, Dst Port: 60537
Data (260 bytes)
Frame 6534: Packet, 302 bytes on wire (2416 bits), 302 bytes captured (2416 bits) on interface \Device\NPF_{0620817D-A96C-45BB-90CC-D98FA55EDDB3}, id 3
    Section number: 1
    Interface id: 3 (\Device\NPF_{0620817D-A96C-45BB-90CC-D98FA55EDDB3})
    Encapsulation type: Ethernet (1)
    Arrival Time: Nov 25, 2025 13:46:05.255982000 Central Europe Standard Time
    UTC Arrival Time: Nov 25, 2025 12:46:05.255982000 UTC
    Epoch Arrival Time: 1764074765.255982000
    [Time shift for this packet: 0.000000000 seconds]
    [Time delta from previous captured frame: 364.000 microseconds]
    [Time delta from previous displayed frame: 57.000 microseconds]
    [Time since reference or first frame: 1 minute, 19.864145000 seconds]
    Frame Number: 6534
    Frame Length: 302 bytes (2416 bits)
    Capture Length: 302 bytes (2416 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: eth:ethertype:ip:udp:data]
    Character encoding: ASCII (0)
    [Coloring Rule Name: UDP]
    [Coloring Rule String: udp]
Ethernet II, Src: VMware_cf:f8:7b (00:0c:29:cf:f8:7b), Dst: IPv4mcast_5d:70:61 (01:00:5e:5d:70:61)
    Destination: IPv4mcast_5d:70:61 (01:00:5e:5d:70:61)
    Source: VMware_cf:f8:7b (00:0c:29:cf:f8:7b)
    Type: IPv4 (0x0800)
    [Stream index: 19]
Internet Protocol Version 4, Src: 192.168.1.161, Dst: 237.221.112.97
User Datagram Protocol, Src Port: 60538, Dst Port: 60537
Data (260 bytes)

Any help would be appreciated!

I figured it out. It seems that I took “too long” to reinject the packet. But i have a followup question. Are there are guidelines for usermode packet inspection? Are there any packets that I must absolutely inspect in KM as to not delay them “too much”? Also what is considered a long wait in this scenario? Im expecting a few MS tops

EDIT:

I wasnt filtering endpoint closure. Now that I pend endpoint closure until i reinject all packets everything works fine!

1 Like

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.