Reconnection from WiFi to 4G always results in lower transfer speed

mkrn commented 10 months ago

Describe the bug

I tested these scenarios:

Streaming on WiFi. Disconnect Wifi. Connect Wifi. ✅
Streaming on 4G/5G. Disconnect 4G/5G. Connect 4G/5G. ✅
Streaming on 4G/5G. Connect WiFi. Disconnect 4G/5G. ✅
Streaming on 4G/5G. Go to notification center. Return ✅
Streaming on WiFi with good signal. Connect 4G/5G. Disconnect WiFi. => Connection falters, then speed stays very low.

To Reproduce

In SwiftUI Example app.

Increase video bitrate to 3000kbps (Slider max)
Use remote RTMP in Preferences
Display currentBytesOutPerSecond (see delegate)
Start streaming with WiFi AND 4G on
Disconnect WiFi
Watch app reconnect and currentBytesOutPerSecond stay low

(Same issue if you walk out of WiFi range)

Delegate to debug:

extension ViewModel : RTMPConnectionDelegate {
    // MARK: RTMPStreamDelegate
    func connection(_ connection: HaishinKit.RTMPConnection, publishInsufficientBWOccured stream: HaishinKit.RTMPStream) {
        print("insufficientBW", stream.videoSettings.bitRate,  stream.audioSettings.bitRate, connection.currentBytesOutPerSecond * 8)

    }

    func connection(_ connection: HaishinKit.RTMPConnection, publishSufficientBWOccured stream: HaishinKit.RTMPStream) {
        print("sufficientBW",  stream.videoSettings.bitRate, stream.audioSettings.bitRate, connection.currentBytesOutPerSecond * 8)

    }

    func connection(_ connection: HaishinKit.RTMPConnection, updateStats stream: HaishinKit.RTMPStream) {
        let curFps = stream.currentFPS

        let currentBitsPerSecond = connection.currentBytesOutPerSecond * 8;
        let currentMbps = String(format: "%.1f", Double(currentBitsPerSecond) / 1000.0 / 1000.0);
        let fpsStr = "\(max(curFps, 30)) fps   \(currentMbps)Mb/s";
        DispatchQueue.main.async {
            self.fps = fpsStr
        }

}

Expected behavior

After switching or loosing WiFi app should reconnect just as well

Version

main

Smartphone info.

iPhone 13 Pro iOS 16, 17

Additional context

No response

Screenshots

No response

Relevant log output

No response

shogo4405 commented 10 months ago

Unfortunately, I couldn't reproduce it in my environment, so I'm having difficulty finding a solution. I'm considering trying it in a different environment. How about others?

jhays commented 1 week ago

I am still able to reliably reproduce this issue. In my case, I don't think I'm seeing any transfer speed at all after the reconnect.

In order to work around this problem, I have had to implement my own reconnect strategy. In my implementation, when a disconnect happens, but then connectivity is restored, in order to successfully reconnect I am forced to perform the following:

close the connection on the RTMPStream object
nil out the RTMPStream and RTMPConnection objects
Initialize new RTMPStream and RTMPConnection objects
connect and publish using the same URL and stream name as the previous stream

Following this pattern, I am able to reliably reconnect and keep data flowing from the client to server. However this is not ideal, as nilling out the RTMPStream and RTMPConnection objects means I am not able to keep local recording active through a disconnection event. Ideally I would like to keep an uninterrupted local recording that runs even while a disconnect/reconnect of the RTMP stream occurs.

If I instead attempt to connect and publish again on the same RTMPConnection and RTMPStream objects (the same way the HaishinKit example project handles reconnects), I will run into the bug as described by this thread. HaishinKit will log NetConnection.Connect.Success, but after this point no data will reach the server. Logging the RTMPConnection's currentBytesOutPerSecond value shows 0, confirming that no data is being sent.

In my testing, the repro path I follow involves a phone that is connected to both cellular (typically 5G) as well as Wifi. If I start the broadcast, then shortly after that open control center and disable wifi, the bug is noticed pretty much immediately. I've also tested by walking out of range of the Wifi signal. The phone is still connected through cellular, and HaishinKit will very quickly log that the following connection was a success, but no data gets sent.

However, if I perform another test in which I keep the phone in airplane mode with no cellular connection, and I simply disable and re-enable wifi, it seems the reconnect can work successfully in that case. The issue seems to be something specific about switching between wifi and cellular, which seems to align with the issue as described in this GitHub issue post.

I have attached a log file from a test I ran on the haishin kit example project. In the test I included the RTMPConnectionDelegate code as outlined in original post of this issue thread.

Please let me know if there are any other details I can provide, or any additional tests I can perform on my environment with this reliable repro path to gain further insight. I would love to find a resolution for this issue so that I can support local recording throughout a disconnection/reconnection event.

Thank you

2024-08-07_haishinKit_reconnect_bug_log.txt

shogo4405 commented 4 days ago

I have a hypothesis regarding this issue. I suspect that reusing the Socket instance might be causing some problem. Can you reproduce the issue with the following commit as well? https://github.com/shogo4405/HaishinKit.swift/tree/feature/network-framework

There is a feature to output detailed logs for the Network framework. Please provide the logs using the following branch: https://github.com/shogo4405/HaishinKit.swift/tree/feature/network-framework-logging

You can see the logs like this.

2024-13-07 01:31:47.986 [Info] [com.haishinkit.HaishinKit] [RTMPNWSocket.swift:162] viabilityDidChange(to:) > Optional(Establishment Report:
    Duration: 10ms
    Attempt Started After: 0ms
    Previous Attempts: 0
    tcp (0ms/0ms RTT)
    Proxy not configured, not used, to unknown
    Privacy stance: Not Eligible)

2024-13-07 01:31:47.992 [Info] [com.haishinkit.HaishinKit] [RTMPNWSocket.swift:130] doOutput(data:) > Data Transfer Report:
    Duration: 0ms
    Paths Used: 1
    Interface: lo0[]
    Application Bytes Sent: 293
    Application Bytes Received: 0
    Transport Bytes Sent: 293 (Retransmitted 0)
    Transport Bytes Received: 0 (Duplicate 0, Out-of-Order 0)
    Transport RTT: 1ms (Minimum 2ms, Variance 1ms)
    Transport Congestion Window: 133998
    Transport Slow Start Threshold: 1073725440
    IP Packets Sent: 3
    IP Packets Received: 0
2024-13-07 01:31:47.992 [Info] [com.haishinkit.HaishinKit] [RTMPNWSocket.swift:130] doOutput(data:) > Data Transfer Report:
    Duration: 0ms
    Paths Used: 1
    Interface: lo0[]
    Application Bytes Sent: 153
    Application Bytes Received: 0
    Transport Bytes Sent: 153 (Retransmitted 0)
    Transport Bytes Received: 0 (Duplicate 0, Out-of-Order 0)
    Transport RTT: 1ms (Minimum 2ms, Variance 0ms)
    Transport Congestion Window: 134022
    Transport Slow Start Threshold: 1073725440
    IP Packets Sent: 2
    IP Packets Received: 0

jhays commented 14 hours ago

I've tested the feature/network-framework branch, and I believe I was still able to reproduce the same issue.

In my test, I ran the Example iOS + SwiftUI project on an iPhone 15 Pro Max on iOS 17.5.1. I had the Preference file configured to set the uri and stream name to use our video service, Mux. I then ran the app and started broadcasting. After about 12 seconds, I disabled Wifi from Control Center. Depending on signal, my phone will then attempt to use either 5G or LTE provided by Verizon. The example app attempts to reconnect, but the result is that the currentBytesOutPerSecond seems to still get stuck at 0.

Logs from that attempt are here:

haishinKit-swiftUI-demo-trace-network-framework-wifi-to-cellular.txt

I then tested feature/network-framework-logging and performed the same test. The result was the same. In this log file, we can observe the Wifi connection is no longer available at line 16086. Then, we see Connection viability changed to true on line 16111. After this point, the network logging shows the interface has been changed from en0[] (I believe this is Wifi) to pdp_ip0[lte] (LTE)

haishinKit-network-logging-wifi-to-cellular.txt

In both tests, I did include the RTMPConnectionDelegate code shown at the initial post of this issue, and set the RTMPConnection delegate to self (referencing ViewModel from the SwiftUI example).

Near the end of both log files we see a repeating line: sufficientBW 640000 64000 0 This is the log message added in the RTMPConnectionDelegate, and it is showing how our current bytes out is showing data is no longer sending correctly after the transition form Wifi to cellular.

Please let me know if there are any additional tests I can perform to help diagnose the issue.

Thank you

shogo4405 / HaishinKit.swift