Unhandled exception Message too long in _maintainOutgoing() dtls_server.dart

[Ifilehk]

I don't know why, suddenly started getting this exception that is ending with a Fatal one. Never had that before. Still checking around what could be the reason. Just managed to get the ret values and obviously the message is too long at a certain point. 60 156 315 65536

https://github.com/JKRhb/dtls2/blob/77e11e363bf21c2671aa361e7b23d793cb393f94/lib/src/dtls_server.dart#L338-L352

Unhandled exception:
SocketException: Send failed (OS Error: Message too long, errno = 90), address = ::, port = 8888
#0      _NativeSocket.send (dart:io-patch/socket_patch.dart:1246:34)
#1      _RawDatagramSocket.send (dart:io-patch/socket_patch.dart:2516:15)
#2      _DtlsServerConnection._maintainOutgoing (package:dtls2/src/dtls_server.dart:343:31)
#3      _DtlsServerConnection._maintainState (package:dtls2/src/dtls_server.dart:320:7)
#4      _DtlsServerConnection._incoming (package:dtls2/src/dtls_server.dart:358:5)
#5      DtlsServer._handleSocketRead (package:dtls2/src/dtls_server.dart:100:17)
#6      DtlsServer._startListening.<anonymous closure> (package:dtls2/src/dtls_server.dart:123:11)
#7      _RootZone.runUnaryGuarded (dart:async/zone.dart:1594:10)
#8      _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:339:11)
#9      _BufferingStreamSubscription._add (dart:async/stream_impl.dart:271:7)
#10     _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:776:19)
#11     _StreamController._add (dart:async/stream_controller.dart:650:7)
#12     _StreamController.add (dart:async/stream_controller.dart:598:5)
#13     new _RawDatagramSocket.<anonymous closure> (dart:io-patch/socket_patch.dart:2469:33)
#14     _NativeSocket.issueReadEvent.issue (dart:io-patch/socket_patch.dart:1356:14)
#15     _microtaskLoop (dart:async/schedule_microtask.dart:40:21)
#16     _startMicrotaskLoop (dart:async/schedule_microtask.dart:49:5)
#17     _runPendingImmediateCallback (dart:isolate-patch/isolate_patch.dart:123:13)
#18     _RawReceivePort._handleMessage (dart:isolate-patch/isolate_patch.dart:190:5)

===== CRASH =====
si_signo=Segmentation fault(11), si_code=128, si_addr=(nil)
version=3.0.3 (stable) (Wed May 31 15:35:05 2023 +0000) on "linux_x64"
pid=1230056, thread=1230069, isolate_group=(nil)((nil)), isolate=(nil)((nil))
os=linux, arch=x64, comp=no, sim=no
isolate_instructions=0, vm_instructions=563043ed5920
fp=7f1cf46fede0, sp=7f1cf46fed80, pc=563043ef4b40
  pc 0x0000563043ef4b40 fp 0x00007f1cf46fede0 tcmalloc::ThreadCache::ReleaseToCentralCache(tcmalloc::ThreadCache::FreeList*, unsigned int, int)+0x1b0
  pc 0x0000563043ef5664 fp 0x00007f1cf46fee10 tcmalloc::ThreadCache::DeleteCache(tcmalloc::ThreadCache*)+0x44
-- End of DumpStackTrace

Process finished with exit code 134 (interrupted by signal 6: SIGABRT)

[JKRhb]

Hmm, is this error occurring for the latest published version or for the Git version? And I assume it is happening during the handshake, right? If I try to send application data that is too large I get a DtlsException: error:0A00014E:SSL routines::dtls message too big.

[JKRhb]

Can you try to create an example for reproducing the error again?

[Ifilehk]

Bom dia. OK here are the minimalists client and server code that I use for the test: Client:

import "dart:async";
import "dart:convert";
import "dart:io";

import "package:dtls2/dtls2.dart";

Future<void> main(List<String> arguments) async {
  const bindAddress = "0.0.0.0";
  final DtlsClient dtlsClient = await DtlsClient.bind(bindAddress, 0);

  try {
    print("Connecting ...");

    final dtlsConnection = await dtlsClient.connect(
      InternetAddress("192.168.50.172"),
      8888,
      DtlsClientContext(
        withTrustedRoots: true,
        ciphers: "PSK-AES128-CCM8",
        pskCredentialsCallback: (identityHint) {
          return PskCredentials(
            identity: utf8.encode("Client_identity"),
            preSharedKey: utf8.encode("secretPSK"),
          );
        },
      ),
      timeout: const Duration(seconds: 10),
    );

    print("Connected");

    dtlsConnection.listen(
          (datagram) async {
        print("Received datagram $datagram");
      },
      onDone: () {
        print("DTLS Connection DONE");
      },
      onError: (e) {
        print("DTLS Connection ERROR $e");
      },
    );
  } on DtlsException {
    print("DTLS Connection ERROR: DTLS EXCEPTION");
  } on SocketException {
    print("DTLS Connection ERROR: SOCKET EXCEPTION");
  } on TimeoutException {
    print("DTLS Connection ERROR: TIMEOUT EXCEPTION");
  } catch (e) {
    print("Unhandled exception $e");
  }

  dtlsClient.close();
}

Server:

mport 'dart:async';
import 'dart:convert';
import 'dart:io';

import 'package:dtls2/dtls2.dart';

const ciphers = "PSK-AES128-CCM8";
const bindAddress = "::";
const SERVER_PORT = 8888;

final _serverKeyStore = {
  "Client_identity" : "secretPSK",
  "NewUser"         : "Fig+hpRq5YG72tW/XDQB0UcRxD+fjwJw",
};

Iterable<int>? _serverPskCallback(List<int> identity) {
  final identityString = utf8.decode(identity);

  final psk = _serverKeyStore[identityString];
  print('PSK is: $psk');
  if (psk == null) {
    return null;
  }
  return utf8.encode(psk);
}

Future<void> main(List<String> arguments) async {
  late final DtlsServer socket;

    try {
      socket = await DtlsServer.bind(
          bindAddress,
          SERVER_PORT,
          DtlsServerContext(
            pskKeyStoreCallback: _serverPskCallback,
            ciphers: ciphers,
            identityHint: "This is the identity hint!",
          ));

      print('Server listening on port $SERVER_PORT\n');
      socket.listen( (connection) async {
        print('New connection');
        connection.listen( (Datagram datagram) async {
          print('Received datagram $datagram');
        },
          onDone: () async {
            print('connection closed\n');

          },
          onError: (e) {
            print('connection error $e\n');
          },
        );
      }, onDone: () {
        print("Server closed.");
      }
      );

    } on SocketException catch(e) {
      print('Socket Exception $e');

    } on TimeoutException catch(e) {
      print('Timeout Exception $e');

    } catch(e) {
      print('Unhandled Exception $e');
    }
}

dlts2 is 0.15.0 This is the log:

Server listening on port 8888

New connection
PSK is: secretPSK
Unhandled exception:
SocketException: Send failed (OS Error: Message too long, errno = 90), address = ::, port = 8888
#0      _NativeSocket.send (dart:io-patch/socket_patch.dart:1246:34)
#1      _RawDatagramSocket.send (dart:io-patch/socket_patch.dart:2516:15)
#2      _DtlsServerConnection._maintainOutgoing (package:dtls2/src/dtls_server.dart:342:31)
#3      _DtlsServerConnection._maintainState (package:dtls2/src/dtls_server.dart:320:7)
#4      _DtlsServerConnection._incoming (package:dtls2/src/dtls_server.dart:357:5)
#5      DtlsServer._handleSocketRead (package:dtls2/src/dtls_server.dart:100:17)
#6      DtlsServer._startListening.<anonymous closure> (package:dtls2/src/dtls_server.dart:123:11)
#7      _RootZone.runUnaryGuarded (dart:async/zone.dart:1594:10)
#8      _BufferingStreamSubscription._sendData (dart:async/stream_impl.dart:339:11)
#9      _BufferingStreamSubscription._add (dart:async/stream_impl.dart:271:7)
#10     _SyncStreamControllerDispatch._sendData (dart:async/stream_controller.dart:776:19)
#11     _StreamController._add (dart:async/stream_controller.dart:650:7)
#12     _StreamController.add (dart:async/stream_controller.dart:598:5)
#13     new _RawDatagramSocket.<anonymous closure> (dart:io-patch/socket_patch.dart:2469:33)
#14     _NativeSocket.issueReadEvent.issue (dart:io-patch/socket_patch.dart:1356:14)
#15     _microtaskLoop (dart:async/schedule_microtask.dart:40:21)
#16     _startMicrotaskLoop (dart:async/schedule_microtask.dart:49:5)
#17     _runPendingImmediateCallback (dart:isolate-patch/isolate_patch.dart:123:13)
#18     _RawReceivePort._handleMessage (dart:isolate-patch/isolate_patch.dart:190:5)

===== CRASH =====
si_signo=Segmentation fault(11), si_code=128, si_addr=(nil)
version=3.0.3 (stable) (Wed May 31 15:35:05 2023 +0000) on "linux_x64"
pid=1241904, thread=1241922, isolate_group=(nil)((nil)), isolate=(nil)((nil))
os=linux, arch=x64, comp=no, sim=no
isolate_instructions=0, vm_instructions=55671a314920
fp=7f3dc157ede0, sp=7f3dc157ed80, pc=55671a333a63
  pc 0x000055671a333a63 fp 0x00007f3dc157ede0 tcmalloc::ThreadCache::ReleaseToCentralCache(tcmalloc::ThreadCache::FreeList*, unsigned int, int)+0xd3
  pc 0x000055671a334664 fp 0x00007f3dc157ee10 tcmalloc::ThreadCache::DeleteCache(tcmalloc::ThreadCache*)+0x44
-- End of DumpStackTrace

Process finished with exit code 134 (interrupted by signal 6: SIGABRT)

[Ifilehk]

Same test using dlts2 0.14.1:

Server listening on port 8888

New connection
PSK is: Fig+hpRq5YG72tW/XDQB0UcRxD+fjwJw

===== CRASH =====
si_signo=Segmentation fault(11), si_code=1, si_addr=0x1f0
version=3.0.3 (stable) (Wed May 31 15:35:05 2023 +0000) on "linux_x64"
pid=1245127, thread=1245135, isolate_group=main(0x563befb7a000), isolate=main(0x563befbda800)
os=linux, arch=x64, comp=no, sim=no
isolate_instructions=563becf99920, vm_instructions=563becf99920
fp=563bf0396000, sp=7fd1fa3fde60, pc=7fd1fa27f865
Stack dump aborted because GetAndValidateThreadStackBounds failed.
  pc 0x00007fd1fa27f865 fp 0x0000563bf0396000 /lib/x86_64-linux-gnu/libssl.so.3+0x25865

Process finished with exit code 134 (interrupted by signal 6: SIGABRT)

[JKRhb]

Thank you! With your example, I also get a segmentation fault. Will investigate the reason for that.

[Ifilehk]

By the way with this minimalist example I can reproduce also the Unhandled exception: DtlsException: DTLS Handshake has failed when using a client identity that is not known by the server ...

[JKRhb]

By the way with this minimalist example I can reproduce also the Unhandled exception: DtlsException: DTLS Handshake has failed when using a client identity that is not known by the server ...

Oh, yeah, that is good to know – have you tried out #85 yet by the way? I think that one could be a potential fix.

[Ifilehk]

What I don't understand is why is it happening now? Checked my libcrypto strings /usr/lib/x86_64-linux-gnu/libcrypto.so.3 | grep "^OpenSSL \S\+ [0-9]\+ \S\+ [0-9]\+. Result OpenSSL 3.0.8 7 Feb 2023

[Ifilehk]

Just tried #85. Positive Comment in the related issue

[JKRhb]

What I don't understand is why is it happening now? Checked my libcrypto strings /usr/lib/x86_64-linux-gnu/libcrypto.so.3 | grep "^OpenSSL \S\+ [0-9]\+ \S\+ [0-9]\+. Result OpenSSL 3.0.8 7 Feb 2023

I think I have an idea what the problem is here: The server seems to only encounter a segfault when the client closes the connection (which goes along with a CLOSE NOTIFY message). I think this cannot be handled by the server at the moment for some reason. So far, I think I was only testing both implementations together in scenarios where the server closes the connection. I will try out this route and hopefully be able to provide a fix soon.

[JKRhb]

What's even more interesting: The Segfault only occurs, if you don't send anything from the client to the server before closing the connection client-wise. This makes this problem a somewhat strange edge case.

[Ifilehk]

Yes I can confirm with the server-client example that closing the connection on client side triggers the exception. But in my usecase I don't remember closing the connection client side. Will check that ...

[JKRhb]

One potential fix for the problem appears to be #86. Could you try that one out? At some point, the state management probably needs an overhaul to make things a bit more manageable.

[Ifilehk]

OK will. Thank you

[Ifilehk]

WUNDERBAR. Issue solved !!!

[JKRhb]

Awesome! :) Then I am going to merge #86 and will release a new version soon :)

[JKRhb]

Just released a new version 0.16.0 :) I hope that we fixed all of the remaining bugs now 😅🤞 Thanks again for testing the package and providing feedback! :)

[Ifilehk]

OK will update and keep you updated. Thank you for support !!!!