dart-archive / sdk

The Dartino project was an experiment seeking to improve productivity when writing application code for embedded devices.
https://dartino.org
Other
330 stars 36 forks source link

Error after making a large number of HTTP requests #522

Closed sgjesse closed 8 years ago

sgjesse commented 8 years ago

After performing 31262 HTTP requests using the program below the following exception is thrown:

Performing request 31262
Performing request 31263
NoSuchMethodError(8, 306178)
Frame  0: Function(145916)
Frame  1: Function(144124)
Frame  2: Function(144092)
Frame  3: Function(143408)

Decoding the stacktrace with pkg/dartino_compiler/bin/decode_stacktraces.dart:

NoSuchMethodError: Null.asUint8List
   0: <unknown function>
   1: <unknown function>
   2: <unknown function>
   3: <unknown function>

This might be related to #520.

This is the program on the device:

import 'dart:convert';
import 'dart:dartino';

import 'package:http/http.dart';
import 'package:socket/socket.dart';
import 'package:stm32/ethernet.dart';

const String host = "192.168.0.100";
const int port = 8081;
const String path = "/message.json";

main() {
  print('Hello from Dartino');
  if (!ethernet.initializeNetworkStack(
      const InternetAddress(const <int>[192, 168, 0, 10]),
      const InternetAddress(const <int>[255, 255, 255, 0]),
      const InternetAddress(const <int>[192, 168, 0, 1]),
      const InternetAddress(const <int>[8, 8, 8, 8]))) {
    throw 'Failed to initialize network stack';
  }

  print('Network up, requesting DHCP configuration...');

  int i = 0;
  int sleepInterval = 5000;
  while (NetworkInterface.list().isEmpty) {
    printNetworkInfo();
    sleep(sleepInterval);
    i++;
    print("waited ${i*sleepInterval} ms");
  }

  int requestCount = 0;
  while (true) {
    requestCount++;
    print('Performing request $requestCount');
    Map json = downloadData(host, port, path);
    if (json == null) {
      print('Failed to make HTTP request');
      sleep(1000);
    }
  }
}

void printNetworkInfo() {
  bool eth0Connected = false;
  for (NetworkInterface interface in
      NetworkInterface.list(includeLoopback: true)) {
    print("${interface.name}:");
    for (InternetAddress address in interface.addresses) {
      print("  $address");
    }
    print("  ${interface.isConnected ? 'connected' : 'not connected'}");
    if (interface.name == 'eth0' && interface.isConnected) eth0Connected = true;
  }
}

/// Download a JSON object from the server [host]:[port] at [uri] and return the
/// parsed result as a Dart map.
Map downloadData(String host, int port, String uri) {
  Socket socket;
  try {
    socket = new Socket.connect(host, port);
    HttpConnection https = new HttpConnection(socket);
    HttpRequest request = new HttpRequest(uri);
    request.headers["Host"] = host;
    HttpResponse response = https.send(request);
    if (response.statusCode != HttpStatus.OK) {
      print("Failed to receive document: ${response.statusCode}");
      return null;
    }
    HttpHeaders headers = response.headers;
    String contentType = headers.contentType;
    if (contentType == "application/json") {
      Object result = JSON.decode(new String.fromCharCodes(response.body));
      if (result is! Map) {
        print("Expected a map.");
        return null;
      }
      return result;
    } else {
      print("Expected content of type 'application/json'"
            " but got '$contentType'.");
      return null;
    }
  } on SocketException catch (e) {
    print(e);
    return null;
  } finally {
    socket?.close();
  }
}

Did another run, and there it happened after 32800 requests:

Closing socket c07ff550 2
Performing request 32798
Closing socket c07ff550 2
Performing request 32799
Closing socket c07ff550 2
Performing request 32800
Closing socket c07ff550 2
Performing request 32801
Closing socket c07ff550 2
NoSuchMethodError(8, 306178)
Frame  0: Function(145916)
Frame  1: Function(144124)
Frame  2: Function(144092)
Frame  3: Function(143408)
Dartino program exited

This was with

printf("Closing socket %08x %d\n", socket, handle);

added to UnregisterAndCloseSocket.

sgjesse commented 8 years ago

This can still happen. This time after 100000+ requests.

NoSuchMethodError(115476, 258050)
Frame  0: Function(19008)
Frame  1: Function(18468)
Frame  2: Function(19808)
Frame  3: Function(18168)

Decoded stack trace:

NoSuchMethodError: Null.asUint8List
   0: sendRequest
   1: main
   2: callMain
   3: entry

I am a bit suspicious about the method asUint8List as is not called in sendRequest.

It does not look like an OOM from the C-heap

(gdb) p/x theheap
$1 = {size = 0x712000, remaining = 0x8aae8, free_lists = {0xc07fba98, 
    0xc07fc120, 0xc07fc568, 0xc07fbca0, 0xc07fc218, 0x0 <repeats 11 times>, 
    0xc07fc020, 0x0, 0x0, 0x0, 0x0, 0xc07fbb88, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 
    0xc07fbd38, 0x0, 0x0, 0x0, 0x0, 0x2001a418, 0x0 <repeats 28 times>, 
    0xc07fd008, 0x0 <repeats 73 times>}, free_list_bits = {0xf8008408, 
    0x40000002, 0x0, 0x0, 0x0}}
sgjesse commented 8 years ago

Ran another test (on 8814b7582f453ccb9193eaa5e1223c9006754621) which failed after 148720 requests.

With the change in https://github.com/dartino/sdk/commit/b6bb9c2540731318174ba3747c95f3b73b718a81 stack traces are improved, and I get this:

VM Configuration 32 32
NoSuchMethodError(115648, 258050)
Frame  0: Function(19112) Bytecode(292)
Frame  1: Function(18588) Bytecode(90)
Frame  2: Function(19912) Bytecode(0)
Frame  3: Function(18288) Bytecode(51)

which decodes to

NoSuchMethodError: Null.asUint8List
   0: sendRequest samples/stm32f746g-discovery/http_json_sample.dart:79:3
   1: main samples/stm32f746g-discovery/http_json_sample.dart:59:10
   2: callMain lib/system/system.dart:72:24
   3: entry lib/system/system.dart:97:14

However the line in the sendRequest method is just the line with try {.

The diff to samples/stm32f746g-discovery/http_json_sample.dart is

diff --git a/samples/stm32f746g-discovery/http_json_sample.dart b/samples/stm32f746g-discovery/http_json_sample.dart
index 6fe8902..65726ce 100644
--- a/samples/stm32f746g-discovery/http_json_sample.dart
+++ b/samples/stm32f746g-discovery/http_json_sample.dart
@@ -52,15 +52,18 @@ main() {

   Map data;

+  int count = 0;
+  while (true) {
   // Make an HTTP request and print message.
-  print('Making HTTP request...');
+  print('Making HTTP request ${++count}...');
   data = sendRequest(host, path, secure: false);
   printMessage(data['message']);

   // Make an HTTPS request and print message.
-  print('Making HTTPS request...');
-  data = sendRequest(host, path, secure: true);
-  printMessage(data['message']);
+  //print('Making HTTPS request...');
+  //data = sendRequest(host, path, secure: true);
+  //printMessage(data['message']);
+  }
 }

 void printMessage(String message) {
sgjesse commented 8 years ago

Captured the issue with the try/finally block removed

VM Configuration 32 32
NoSuchMethodError(103164, 240642)
Frame  0: Function(26884) Bytecode(17)
Frame  1: Function(16976) Bytecode(13)
Frame  2: Function(17072) Bytecode(13)
Frame  3: Function(48632) Bytecode(3)
Frame  4: Function(66020) Bytecode(41)
Frame  5: Function(65920) Bytecode(1)
Frame  6: Function(46768) Bytecode(11)
Frame  7: Function(34856) Bytecode(125)
Frame  8: Function(35184) Bytecode(3)
Frame  9: Function(17620) Bytecode(76)
Frame  10: Function(17112) Bytecode(50)
Frame  11: Function(18212) Bytecode(0)
Frame  12: Function(16812) Bytecode(51)
NoSuchMethodError: Null.asUint8List
   0: Object.noSuchMethod lib/core/core_patch.dart:34:7
   1: Object._noSuchMethod lib/core/core_patch.dart:47:12
   2: Object._noSuchMethodTrampoline 
   3: Uint8List.view third_party/dart/sdk/lib/typed_data/typed_data.dart:814:12
   4: _HttpParser._peek pkg/http/lib/http.dart:385:17
   5: _HttpParser._expect pkg/http/lib/http.dart:379:9
   6: _HttpParser.parse pkg/http/lib/http.dart:217:5
   7: HttpConnection.send pkg/http/lib/http.dart:39:12
   8: HttpConnection.send 
   9: sendRequest samples/stm32f746g-discovery/http_json_sample.dart:87:29
   10: main samples/stm32f746g-discovery/http_json_sample.dart:59:10
   11: callMain lib/system/system.dart:72:24
   12: entry lib/system/system.dart:97:14

Turns out that the server closes the connection without sending a response, and that case is not handled by the http package.