Skip to content

dart::io::RawSocket is unexpectly closed on iOS during the data reception #47888

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

Closed
mkulesh opened this issue Dec 9, 2021 · 12 comments
Closed
Labels
area-core-library SDK core library issues (core, async, ...); use area-vm or area-web for platform specific libraries. area-vm Use area-vm for VM related issues, including code coverage, and the AOT and JIT backends. library-io os-ios

Comments

@mkulesh
Copy link

mkulesh commented Dec 9, 2021

I develop a Flutter app that is a remote controller for Onkyo/Pioneer network players and AV receivers. The app communicates with players via TCP using so called "Integra Serial Communication Protocol". For the communication with the receiver, I use Socket and RawSocket classes.

After upgrading Flutter from the version 1.22.6 (Dart version 2.10.5) to Flutter version 2.0.0 (Dart version 2.12.0), I observe a critical regression in the RawSocket class. This, however, only happens on a real iOS device (iPad 7 gen in my case) and only if the app connects to a real Onkyo/Pioneer hardware. The observed behavior is that using Dart 2.12.0 and later, the RawSocket suddenly generates RawSocketEvent.readClosed after reception some portion of data immediately after a successful connection is established.

It does not happen on Dart 2.10.5 and earlier. It does not happen on iOS simulator, macOS, Android, Linux or Windows. It only happens on physical iPad (iOS 14.x and 15.1) with Dart 2.12.0 and later.

This is an example om my MessageChannel class that communicates with the remote device:

class MessageChannel
{
  String _host = "";
  int _port = -1;
  MessageChannelState _state = MessageChannelState.IDLE;
  RawSocket _socket;
  final OnConnected _onConnected;

  MessageChannel(this._onConnected);

  String get getHostAndPort
  => _host + ":" + _port.toString();

  bool get isConnected
  => _state == MessageChannelState.RUNNING;

  void start(String host, int port)
  {
    _host = host;
    _port = port;
    if (_state != MessageChannelState.IDLE)
    {
      return;
    }
    _state = MessageChannelState.CONNECTING;

    RawSocket.connect(_host, _port, timeout: Duration(seconds: 10)).then((RawSocket sock)
    {
      _socket = sock;
      _socket.writeEventsEnabled = false;
      _socket.listen(_onEvent, onDone: () => _onDone(), cancelOnError: false);
      _state = MessageChannelState.RUNNING;
      print("Connected to " + getHostAndPort);
      _onConnected();
    }).catchError((dynamic e)
    {
      _state = MessageChannelState.IDLE;
      print("Disconnected from " + getHostAndPort + ": " + e.toString());
    });
  }

  void stop()
  {
    if (_socket != null)
    {
      _socket.close();
    }
  }

  void _onEvent(RawSocketEvent event)
  {
    switch (event) {
      case RawSocketEvent.read:
        if (_socket.available() > 0)
        {
          print("RawSocketEvent.read: " + _socket.available().toString());
          _onData(_socket.read());
        }
        break;
      case RawSocketEvent.write:
        break;
      case RawSocketEvent.readClosed:
        print("RawSocketEvent.readClosed");
        break;
      case RawSocketEvent.closed:
        break;
      default:
        throw "Unexpected event $event";
    }
  }

  void _onDone()
  {
    _state = MessageChannelState.IDLE;
    _socket = null;
    print("Disconnected from " + getHostAndPort + ": done");
    _onConnected();
  }

  void _onData(Uint8List data)
  {
    String res = "";
    data.forEach((int f)
    {
        res += f.toRadixString(16);
        res += " ";
    });
    print("Data received: [" + res + "]");
  }
}

The problem is that RawSocketEvent.readClosed event is called unexpectedly with the Flutter version 2.0.0 and later, but never called with Flutter 1.22.6 and earlier.

My Flutter 2.0.0 environment:

[✓] Flutter (Channel unknown, 2.0.0, on macOS 12.0.1 21A559 darwin-x64, locale en-GB)
    • Flutter version 2.0.0 at /Volumes/ExtWork/home/family/work/android/flutter
    • Framework revision 60bd88df91 (9 месяцев назад), 2021-03-03 09:13:17 -0800
    • Engine revision 40441def69
    • Dart version 2.12.0

[✓] Android toolchain - develop for Android devices (Android SDK version 29.0.3)
    • Android SDK at /Users/family/work/android/sdk
    • Platform android-30, build-tools 29.0.3
    • ANDROID_HOME = /Users/family/work/android/sdk
    • ANDROID_SDK_ROOT = Users/family/work/android/sdk
    • Java binary at: /Applications/Android Studio.app/Contents/jre/jdk/Contents/Home/bin/java
    • Java version OpenJDK Runtime Environment (build 1.8.0_202-release-1483-b49-5587405)
    • All Android licenses accepted.

[✓] Xcode - develop for iOS and macOS
    • Xcode at /Applications/Xcode.app/Contents/Developer
    • Xcode 13.1, Build version 13A1030d
    • CocoaPods version 1.10.0

[✗] Chrome - develop for the web (Cannot find Chrome executable at /Applications/Google Chrome.app/Contents/MacOS/Google Chrome)
    ! Cannot find Chrome. Try setting CHROME_EXECUTABLE to a Chrome executable.

[✓] Android Studio (version 3.5)
    • Android Studio at /Applications/Android Studio.app/Contents
    • Flutter plugin version 41.1.2
    • Dart plugin version 191.8593
    • Java version OpenJDK Runtime Environment (build 1.8.0_202-release-1483-b49-5587405)

[✓] Connected device (2 available)
    • iPad (mobile)   • 48c6c5fc5e9d64kgujvgcyt1dff41154255a86da • ios        • iOS 15.1
    • macOS (desktop) • macos                                    • darwin-x64 • macOS 12.0.1 21A559 darwin-x64

If I open and close the app on iPad several times, the typical log output is follows:

flutter: Connected to 192.168.1.80:60128 // the app is opened here
flutter: RawSocketEvent.read: 59 // receiver sends a portion of data upon connection
flutter: Data received: [49 53 43 50 0 0 0 10 0 0 0 2b 1 0 0 0 21 31 4e 4a 41 32 2d 68 74 74 70 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 2e 38 30 2f 61 6c 62 75 6d 5f 61 72 74 2e 63 67 69 1a d a ]
flutter: RawSocketEvent.readClosed // connection suddenly closed 
flutter: Disconnected from 192.168.1.80:60128: done // home button on iPad is pressed
flutter: Connected to 192.168.1.80:60128 // the app is opened again using icon on the home screen
flutter: RawSocketEvent.read: 59
flutter: Data received: [49 53 43 50 0 0 0 10 0 0 0 2b 1 0 0 0 21 31 4e 4a 41 32 2d 68 74 74 70 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 2e 38 30 2f 61 6c 62 75 6d 5f 61 72 74 2e 63 67 69 1a d a ]
flutter: RawSocketEvent.readClosed
flutter: Disconnected from 192.168.1.80:60128: done
flutter: Connected to 192.168.1.80:60128
flutter: RawSocketEvent.read: 59
flutter: Data received: [49 53 43 50 0 0 0 10 0 0 0 2b 1 0 0 0 21 31 4e 4a 41 32 2d 68 74 74 70 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 2e 38 30 2f 61 6c 62 75 6d 5f 61 72 74 2e 63 67 69 1a d a ]
flutter: RawSocketEvent.readClosed
flutter: Disconnected from 192.168.1.80:60128: done

Please note that "RawSocketEvent.readClosed" is logged that indicates RawSocketEvent.readClosed event is received.

The same code running on the same iPad with the same external receiver, but with Flutter 1.22.6

family@mac-mini bug % dart --version
Dart SDK version: 2.10.5 (stable) (Tue Jan 19 13:05:37 2021 +0100) on "macos_x64"

generates following output:

flutter: Connected to 192.168.1.80:60128
flutter: RawSocketEvent.read: 59
flutter: Data received: [49 53 43 50 0 0 0 10 0 0 0 2b 1 0 0 0 21 31 4e 4a 41 32 2d 68 74 74 70 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 2e 38 30 2f 61 6c 62 75 6d 5f 61 72 74 2e 63 67 69 1a d a ]
flutter: Disconnected from 192.168.1.80:60128: done
flutter: Connected to 192.168.1.80:60128
flutter: RawSocketEvent.read: 59
flutter: Data received: [49 53 43 50 0 0 0 10 0 0 0 2b 1 0 0 0 21 31 4e 4a 41 32 2d 68 74 74 70 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 2e 38 30 2f 61 6c 62 75 6d 5f 61 72 74 2e 63 67 69 1a d a ]
flutter: Disconnected from 192.168.1.80:60128: done
flutter: Connected to 192.168.1.80:60128
flutter: RawSocketEvent.read: 59
flutter: Data received: [49 53 43 50 0 0 0 10 0 0 0 2b 1 0 0 0 21 31 4e 4a 41 32 2d 68 74 74 70 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 2e 38 30 2f 61 6c 62 75 6d 5f 61 72 74 2e 63 67 69 1a d a ]
flutter: Disconnected from 192.168.1.80:60128: done

Please note that RawSocketEvent.readClosed is never called here.

Steps to reproduce:

  • ensure that Flutter 2.0.0 or later is installed. The problem is also reproducible with Flutter 2.8.0 released today.
  • create a new Flutter project: 'Flutter create bug'
  • Replace lib/main.dart by this attached file
    main.dart.zip
  • Ensure that any Onkyo receiver is available in local network or in internet and is in stand-by mode
  • Replace the IP address in the variable HOST by the IP of this Onkyo device
  • Run the app on iPad 7 in debug mode
  • Press Home button on iPad
  • Open app using shortcut on home screen
    expected behavior: app is opened, no log RawSocketEvent.readClosed appears
    observed behavior: log RawSocketEvent.readClosed appears, connection to receiver is closed
  • Repeat the last two steps 10-15 times
@stevemessick stevemessick added the area-core-library SDK core library issues (core, async, ...); use area-vm or area-web for platform specific libraries. label Dec 9, 2021
@mkulesh
Copy link
Author

mkulesh commented Apr 23, 2022

Hi @lrhn! is there any updates regarding this issue? If you need any additional information or logs, please let me known!

@lrhn lrhn added the area-vm Use area-vm for VM related issues, including code coverage, and the AOT and JIT backends. label Apr 25, 2022
@lrhn
Copy link
Member

lrhn commented Apr 25, 2022

Adding the VM people, since they are maintaining the dart:io library.

@aam
Copy link
Contributor

aam commented Apr 25, 2022

sorrry @mkulesh , this felt through the cracks.
Can you clarify the concern please.
If I interpret logs from 1.22.6 compared with later ones it looks like the behavior is identical only difference is new readClosed event coming in the stream:

1.22.6

flutter: Data received: [49 53 43 50 0 0 0 10 0 0 0 2b 1 0 0 0 21 31 4e 4a 41 32 2d 68 74 74 70 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 2e 38 30 2f 61 6c 62 75 6d 5f 61 72 74 2e 63 67 69 1a d a ]
flutter: Disconnected from 192.168.1.80:60128: done

later one

flutter: Data received: [49 53 43 50 0 0 0 10 0 0 0 2b 1 0 0 0 21 31 4e 4a 41 32 2d 68 74 74 70 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 2e 38 30 2f 61 6c 62 75 6d 5f 61 72 74 2e 63 67 69 1a d a ]
flutter: RawSocketEvent.readClosed // connection suddenly closed 
flutter: Disconnected from 192.168.1.80:60128: done // home button on iPad is pressed

Are there any events in the log that indicate that raw socket stayed open longer in 1.22.6?

@aam
Copy link
Contributor

aam commented Apr 25, 2022

@mkulesh wrote

Steps to reproduce:
...
Ensure that any Onkyo receiver is available in local network or in internet and is in stand-by mode

Having physical Onkyo receiver available makes this harder to reproduce. Were you able to further this repro so it doesn't require the receiver?

@mkulesh
Copy link
Author

mkulesh commented Apr 26, 2022

Hi @aam,
thank you for quick response.

If I interpret logs from 1.22.6 compared with later ones it looks like the behavior is identical only difference is new readClosed event coming in the stream

Yes, the only difference between Flitter 1.22.x and 2.x is the additional log line RawSocketEvent.readClosed, which indicates that RawSocketEvent.readClosed event was suddenly called:

  void _onEvent(RawSocketEvent event)
  {
    switch (event) {
      case RawSocketEvent.read:
        if (_socket.available() > 0)
        {
          print("RawSocketEvent.read: " + _socket.available().toString());
          _onData(_socket.read());
        }
        break;
      case RawSocketEvent.write:
        break;
      case RawSocketEvent.readClosed:
        print("RawSocketEvent.readClosed");
        break;
      case RawSocketEvent.closed:
        break;
      default:
        throw "Unexpected event $event";
    }
  }

For the app it has an effect that socket is suddenly closed and can not be used anymore.

Are there any events in the log that indicate that raw socket stayed open longer in 1.22.6?

Not in this example. During test, I just waiting a couple of minutes after the first data packet is received and logged. I have never observed the readClosed event in 1.22.6.

Having physical Onkyo receiver available makes this harder to reproduce. Were you able to further this repro so it doesn't require the receiver?

Unfortunately yes, you are right. Using shodan.io, it is possible to find some public onkyo devices in Internet (search string: onkyo), but both versions of Flutter are working stable on all these devices. I believe this is a kind of timing problem, since onkyo receiver in the local network answers connection really fast. When connection is open while the receiver is in standby, it immediately sends a portion of status information and the socket closes. If we try to connect any device in the internet, there is a delay between connection and data reception due to global latency and the socket still be open. When the receiver in the local network is playing something, there is also a delay between the connection and first data reception and the socket still be also alive. It is possible that some timings are changed between Flutter 1.22.x and 2.x?

I also tried my HTR with iPhone 7, the behavior is the same as with iPad.

If you need any kind of technical logging or additional information, I will be happy to collect it for you.

@mkulesh
Copy link
Author

mkulesh commented May 25, 2022

Hi @aam,
I am able to reproduce the problem without a real Onkyo receiver. In order to achieve it, I build a small server that simulates some Onkyo firmware behavior. Please take a look on the new HTR below.

[✓] Flutter (Channel unknown, 1.22.6, on macOS 12.2.1 21D62 darwin-x64, locale en-GB)
[✓] Android toolchain - develop for Android devices (Android SDK version 30.0.3)
[✓] Xcode - develop for iOS and macOS (Xcode 13.3.1)
[!] Android Studio (version 4.1)
    ✗ Flutter plugin not installed; this adds Flutter specific functionality.
    ✗ Dart plugin not installed; this adds Dart specific functionality.
[✓] Connected device (2 available)
  • Create a project
    flutter create bug
  • In the bug project, create a directory 'server'
    cd bug && mkdir server
  • note the IP address of this machine (in my case 192.168.1.6):
    ifconfig
  • copy the downloaded file ios-disconnection-server.dart into the directory server and start it:
    cd server && dart ios-disconnection-server.dart
    good: the server logs "Started server: InternetAddress('0.0.0.0', IPv4):60128. Press CTRL-C key to stop." and waits for the connection
  • Copy ios-disconnection-raw.dart into lib directory and rename it to main.dart. Edit the constant variable HOST and set your IP address noted in previous steps:
    const String HOST = "192.168.1.6";
  • Run the project on a real iPad or iPhone (not in simulator)
    good: server logs
    Connection from 192.168.1.50:54516
    good: client (iOS) logs
    Data received: [49 53 43 50 0 0 0 10 0 0 0 2b 1 0 0 0 21 31 4e 4a 41 32 2d 68 74 74 70 3a 2f 2f 31 39 32 2e 31 36 38 2e 31 2e 38 30 2f 61 6c 62 75 6d 5f 61 72 74 2e 63 67 69 1a d a ]
  • Close the app using "Home" button on the iOS device and open it again using the icon on the home screen. Repeat this step at least 10 times.
  • desired: server logs:
Connection from 192.168.1.50:54516
Client left: 192.168.1.50:54516
Connection from 192.168.1.50:54517
Client left: 192.168.1.50:54517
Connection from 192.168.1.50:54518
Client left: 192.168.1.50:54518
Connection from 192.168.1.50:54519
Client left: 192.168.1.50:54519
Connection from 192.168.1.50:54520
Client left: 192.168.1.50:54520
Connection from 192.168.1.50:54521

i.e a single pair "Connection from/Client left" is logged for each app resume
This is a desired behavior, i.e. client (iOS) opens a single connection on each RawSocket.connect. For the newest Flutter it is, however, not the case.

  • Install any Flutter >2.0, in my case 2.8.1, but the behavior is also reproducible with 3.0.1
[✓] Flutter (Channel unknown, 2.8.1, on macOS 12.2.1 21D62 darwin-x64, locale en-GB)
[✓] Android toolchain - develop for Android devices (Android SDK version 30.0.3)
[✓] Xcode - develop for iOS and macOS (Xcode 13.3.1)
[✓] Android Studio (version 4.1)
[✓] Connected device (2 available)
  • Refresh the project
    flutter clean && flutter pub get
  • Run the server and client again. Start and stop the app at least 10 times as in the previous step.
    bad: for some app run, RawSocket.connect creates 2 (in words: two) connections simultaneously where the second connection is immediately closed. Since the Onkyo firmware does not allow two connections from the same remote host on the same server port, it closes the first connection as well:
Connection from 192.168.1.50:55035
Client left: 192.168.1.50:55035
Connection from 192.168.1.50:55037
Client left: 192.168.1.50:55037
Connection from 192.168.1.50:55039
Connection from 192.168.1.50:55040
Client left: 192.168.1.50:55040
Client left: 192.168.1.50:55039
Connection from 192.168.1.50:55041
Client left: 192.168.1.50:55041
Connection from 192.168.1.50:55043
Connection from 192.168.1.50:55044
Client left: 192.168.1.50:55044
Client left: 192.168.1.50:55043
Connection from 192.168.1.50:55045
Connection from 192.168.1.50:55046
Client left: 192.168.1.50:55046
Client left: 192.168.1.50:55045
Connection from 192.168.1.50:55047
Connection from 192.168.1.50:55048
Client left: 192.168.1.50:55048
Client left: 192.168.1.50:55047

In my server emulator, I skipped to implement the logic that closes all connections when two or more connections from the same remote host on the same server port are detected. Therefore, app still be always connected. But, again, a real Onkio/Pioneer receiver do it.

  • Run the same client on macOS or Android device:
    good: as for older Flutter, a single pair "Connection from/Client left" is logged for each app resume

My question is: why new Flutter opens two connection for a single RawSocket.connect event on a real iOS device? How can I ensure in my client code, that only one single connection will be opened (due to restrictions of the Onkyo server firmware)?

@mkulesh
Copy link
Author

mkulesh commented May 31, 2022

Hi @aam,
is there any update about this issue. Is my new how-to-reproduce helpful?

@mraleph
Copy link
Member

mraleph commented May 31, 2022

Based on the symptoms this is most likely related to #41451 and associated fix d7483c3, which changed socket code to try concurrent connection over IPv4 and IPv6 and choosing whatever succeeds to work-around some IPv6 connectivity issues. Though it is pretty bizarre that this would cause any sort of issues when connecting with IP addresses rather than hostnames.

Could you try to change your code to pass InternetAddress(host) instead of host to connect and see if it changes anything?

/cc @brianquinlan

@aam
Copy link
Contributor

aam commented May 31, 2022

Hi @aam, is there any update about this issue. Is my new how-to-reproduce helpful?

Sorry @mkulesh , didn't get a change to run a repro yet, but @mraleph hypothesis sounds right.
Use of ip address instead of a name should also help.

It seems that concurrent lookup of ipv4/ipv6 addresses affected several folks: #48652, #46102.

@mkulesh
Copy link
Author

mkulesh commented May 31, 2022

Hi @aam, @mraleph

Thank you for the proposal to pass InternetAddress(host) instead of host. I tested it with both RawSocket and Socket classes. Both work with this change as desired, i.e the use of InternetAddress(host) instead of host ensures that only one connection will be opened instead of two. This is a working solution for me. May be just more documentation for connect method and using of InternetAddress would be nice...

If you want please feel free to close the issue.

@sa-we
Copy link

sa-we commented Jul 8, 2022

Hi @mkulesh, @aam, @mraleph

Many thanks for these helpful information. I've spent a lot of time to solve this problem. I store the hostIP as a String in my app settings. To connect the socket i used:

String? hostIp = Settings.getValue('key-HostIP', defaultValue: Constants.initHostIP);
String? hostPort = Settings.getValue('key-HostPort', defaultValue: Constants.initHostPort);

socket = await Socket.connect(hostIp, int.parse(hostPort!), timeout: const Duration(seconds: 
Constants.connectingTimeOutSeconds));

This results in a similar behavior like in @mkulesh problem. The socket opens two times. The first connection will be promptly closed and the second one alive. The server tries to answer to the first connection and the error occurs.

But it's only in the iOS version and only at real devices not in the simulator environment. To cast the String as InternetAddress(hostIp) solves the problem to me.

socket = await Socket.connect(InternetAddress(hostIp!), int.parse(hostPort!), timeout: const Duration(seconds: 
Constants.connectingTimeOutSeconds));

Tarmslitaren added a commit to Tarmslitaren/FrosthavenAssistant that referenced this issue Jan 23, 2023
@brianquinlan
Copy link
Contributor

I think that this should have been fixed in d884d1a (so any Dart version >= 3 should include it).

With that change, InternetAddress.lookup is never called when the host is an IP address string and the address family of the address is always used. For example, Socket.connect("127.0.0.1", 80) will only attempt to use IPv4 because the host parameter is an IPv4 address.

Please reopen if I missed something.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area-core-library SDK core library issues (core, async, ...); use area-vm or area-web for platform specific libraries. area-vm Use area-vm for VM related issues, including code coverage, and the AOT and JIT backends. library-io os-ios
Projects
None yet
Development

No branches or pull requests

7 participants