NEVirtualInterface processing read event

I've implemented a custom VPN app for macOS (Packet Tunnel Provider, network extension), which is already available at the App Store. For most of the users everything works great.

The question here is about some other users who reported a problem - when they use my app, it starts good but after a short time, all traffic is extremely slow.

Thos are very suspicious logs from their Console:

“kernel: (Sandbox) Sandbox: myAppExtenstion(8025) deny(1) file-read-data /Users/ahale/Library/Preferences/com.apple.LaunchServices/com.apple.launchservices.secure.plist”

After the above logs, they get a massive amount (over 42000) of these logs “myAppExtension: (NetworkExtension) NEVirtualInterface processing read event”.

What are those logs mean? How can I fix, or at least debug this issue? I can't reproduce it and it happens only for some of the customers.
How can I get more helpful information on this issue?

What are those logs mean? How can I fix, or at least debug this issue?

My guess is that these logs are letting you know that NEPacketTunnelFlow is having an issue reding packets from the virtual interface. I would start with readPacketObjects / readPackets to see if that gives you any clues.


Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com
Thanks for the suggestion, but what do you mean by "start with readPackets" ? It's used for reading IP packets from the TUN interface, but it can't fail / report error in any way AFAIK

It's used for reading IP packets from the TUN interface, but it can't fail / report error in any way AFAIK

You are correct, there is no not error passed into that context, my suggestion was for debugging purposes in case you need to recover from a larger issue with your tunnel while this happens.


Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com
Using Instruments, I can see a lot of small allocations around packetFlow.writePackets().

Can you please look at this short (and simplified) code and check if something is wrong? I can also submit a DTS for this case if needed.

This is the relevant code: ondatarecv_fn() is a callback function from C, with a pointer to one packet.
I'm converting the pointer into a Data, and write it to the packetFlow.
I've added the autorelease there because without it - the app physical footprint is huge. But I think that after some time the VPN is connected, this autorelease pool causes other problems.
Without this autorelease there are many Data() allocations.


Code Block
func on_data_recv_fn(_ buf: UnsafeMutablePointer<CChar>?, length: CInt, user_data: UnsafeMutableRawPointer?) -> CInt {
    var succeededWriting = 0
        buf?.withMemoryRebound(to: UInt8.self, capacity: Int(length), { bufAddress in
            autoreleasepool {
                let data = Data(bytes: bufAddress, count: Int(length))
                succeededWriting =  PacketTunnelProvider.sharedInstance.packetFlow.writePackets([data], withProtocols: [PacketTunnelProvider.protocolTypeIPv4])
            }
        })
    return CInt(succeededWriting)
}

P.S - regarding the autoreleasepool, it's becoming a very big pool, I'm not sure it drains correctly.

I've submitted a DTS -
752661142

Using Instruments, I can see a lot of small allocations around packetFlow.writePackets().

This does not surprise me that this would be a hotspot as I'm sure this logic is processed a lot in your program as packets are being written back to the interface. The key question here is do you see see memory not being released in instruments? It sounds like, the answer to this is no, based on your mention about the memory footprint, but I just want to confirm.

Also, if I think about the sequence of events here, I'm wondering if it goes something like: read bytes from the wire, remove any custom encapsulation or formatting your tunnel has on this data from the server, and then write it back to the interface. If I am correct then this would include some manipulation of that original data off the wire and it may be worth looking at this process as well. If I am not correct and you are reading right from the wire and writing to the interface, what format is the data being read from off the wire? Is it of type Data as well?


Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com
Thanks for the reply! Just in case you missed it, I also submitted a DTS request - 752661142.

As for your questions - I'm working with DTLS protocol:
For sending traffic - I'm reading data from the packetFlow, adding to it some headers, using openSSL and send it.
For the other side I'm doing the opposite - I'm getting it decrypted via openSSL, removing some headers, and only then writing it to the packetFlow. I'm not working with Data directly, I'm getting a char* (C string), hence the conversion I have to make. Also, in case it's relevant - I'm writing to packetFlow one packet at a time (and not array full of packets).

And as you said, I'm not seeing any leaks, but I'm not sure if it's ok that the app will have a huge physical footprint



Thanks for the reply! Just in case you missed it, I also submitted a DTS request - 752661142.

I did see this last night, thank you! I grabbed it and assigned it my queue.

I'm not working with Data directly, I'm getting a char* (C string), hence the conversion I have to make.

Thank you for the clarification here, when I seen the UnsafeMutablePointer<CChar> type being passed in here I had thought that is what might be happening.



Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com
NEVirtualInterface processing read event
 
 
Q