[ VM / Service ] Add --log_service_response_sizes=<log.csv> debug option

Providing `--log_service_response_sizes` will cause the VM to log VM service
response sizes to the provided file in CSV format.

Also added `--service_response_sizes_directory` to the service test
runner to allow for collecting response size data for the entire service
test suite.

TEST=Local

Change-Id: I7aaf4ba936e2593e67d46ff9052e2130374ef461
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/226805
Reviewed-by: Siva Annamalai <asiva@google.com>
Commit-Queue: Ben Konyi <bkonyi@google.com>

pkg/test_runner/lib/src/configuration.dart

@@ -64,6 +64,7 @@ class TestConfiguration {
       this.keepGeneratedFiles,
       this.sharedOptions,
       String packages,
+      this.serviceResponseSizesDirectory,
       this.suiteDirectory,
       this.outputDirectory,
       this.reproducingArguments,
@@ -176,6 +177,7 @@ class TestConfiguration {
     return _packages;
   }
 
+  final String serviceResponseSizesDirectory;
   final String outputDirectory;
   final String suiteDirectory;
   String get babel => configuration.babel;

pkg/test_runner/lib/src/options.dart

@@ -338,7 +338,10 @@ has been specified on the command line.''',
         hide: true),
     _Option.bool('print_passing_stdout',
         'Print the stdout of passing, as well as failing, tests.',
-        hide: true)
+        hide: true),
+    _Option('service_response_sizes_directory',
+        'Log VM service response sizes in CSV files in the provided directory',
+        hide: true),
   ];
 
   /// For printing out reproducing command lines, we don't want to add these
@@ -777,6 +780,8 @@ has been specified on the command line.''',
           localIP: data["local_ip"] as String,
           sharedOptions: sharedOptions,
           packages: data["packages"] as String,
+          serviceResponseSizesDirectory:
+              data['service_response_sizes_directory'] as String,
           suiteDirectory: data["suite_dir"] as String,
           outputDirectory: data["output_directory"] as String,
           reproducingArguments:

pkg/test_runner/lib/src/test_suite.dart

@@ -763,6 +763,8 @@ class StandardTestSuite extends TestSuite {
           ...vmOptionsList[vmOptionsVariant],
           ...extraVmOptions,
           if (emitDdsTest) '-DUSE_DDS=true',
+          if (configuration.serviceResponseSizesDirectory != null)
+            '-DSERVICE_RESPONSE_SIZES_DIR=${configuration.serviceResponseSizesDirectory}',
         ];
         var isCrashExpected = expectations.contains(Expectation.crash);
         var commands = _makeCommands(

runtime/observatory/tests/service/test_helper.dart

@@ -18,6 +18,10 @@ export 'service_test_common.dart' show DDSTest, IsolateTest, VMTest;
 /// Determines whether DDS is enabled for this test run.
 const bool useDds = const bool.fromEnvironment('USE_DDS');
 
+/// The directory to output VM service response size data files to.
+const String serviceResponseSizesDir =
+    const String.fromEnvironment('SERVICE_RESPONSE_SIZES_DIR');
+
 /// The extra arguments to use
 const List<String> extraDebuggingArgs = ['--lazy-async-stacks'];
 
@@ -178,6 +182,15 @@ class _ServiceTesteeLauncher {
     if (!testeeControlsServer) {
       fullArgs.add('--enable-vm-service:$port');
     }
+    if (serviceResponseSizesDir != null) {
+      // Dump service response size details to a CSV. This feature is not used
+      // on the build bots and the generated output will persist after the test
+      // has completed.
+      final dir = path.prettyUri(serviceResponseSizesDir);
+      final testName = path.withoutExtension(path.basename(args.last));
+      final logName = '${testName}_${useDds ? "" : "no_"}dds_sizes.csv';
+      fullArgs.add('--log_service_response_sizes=$dir/$logName');
+    }
     fullArgs.addAll(args);
 
     return _spawnCommon(dartExecutable, fullArgs, <String, String>{});

runtime/observatory_2/tests/service_2/test_helper.dart

@@ -20,6 +20,10 @@ export 'service_test_common.dart' show DDSTest, IsolateTest, VMTest;
 /// Determines whether DDS is enabled for this test run.
 const bool useDds = const bool.fromEnvironment('USE_DDS');
 
+/// The directory to output VM service response size data files to.
+const String serviceResponseSizesDir =
+    const String.fromEnvironment('SERVICE_RESPONSE_SIZES_DIR');
+
 /// The extra arguments to use
 const List<String> extraDebuggingArgs = ['--lazy-async-stacks'];
 
@@ -178,6 +182,15 @@ class _ServiceTesteeLauncher {
     if (!testeeControlsServer) {
       fullArgs.add('--enable-vm-service:$port');
     }
+    if (serviceResponseSizesDir != null) {
+      // Dump service response size details to a CSV. This feature is not used
+      // on the build bots and the generated output will persist after the test
+      // has completed.
+      final dir = path.prettyUri(serviceResponseSizesDir);
+      final testName = path.withoutExtension(path.basename(args.last));
+      final logName = '${testName}_${useDds ? "" : "no_"}dds_sizes.csv';
+      fullArgs.add('--log_service_response_sizes=$dir/$logName');
+    }
     fullArgs.addAll(args);
 
     return _spawnCommon(dartExecutable, fullArgs, <String, String>{});

runtime/vm/dart.cc

@@ -343,6 +343,7 @@ char* Dart::DartInit(const uint8_t* vm_isolate_snapshot,
   Isolate::InitVM();
   UserTags::Init();
   PortMap::Init();
+  Service::Init();
   FreeListElement::Init();
   ForwardingCorpse::Init();
   Api::Init();
@@ -802,6 +803,7 @@ char* Dart::Cleanup() {
   ShutdownIsolate();
   vm_isolate_ = NULL;
   ASSERT(Isolate::IsolateListLength() == 0);
+  Service::Cleanup();
   PortMap::Cleanup();
   UserTags::Cleanup();
   IsolateGroup::Cleanup();

runtime/vm/service.cc

@@ -72,6 +72,56 @@ DEFINE_FLAG(bool,
             "Print a message when an isolate is paused but there is no "
             "debugger attached.");
 
+DEFINE_FLAG(
+    charp,
+    log_service_response_sizes,
+    nullptr,
+    "Log sizes of service responses and events to a file in CSV format.");
+
+void* Service::service_response_size_log_file_ = nullptr;
+
+void Service::LogResponseSize(const char* method, JSONStream* js) {
+  if (service_response_size_log_file_ == nullptr) {
+    return;
+  }
+  Dart_FileWriteCallback file_write = Dart::file_write_callback();
+  char* entry =
+      OS::SCreate(nullptr, "%s, %" Pd "\n", method, js->buffer()->length());
+  (*file_write)(entry, strlen(entry), service_response_size_log_file_);
+  free(entry);
+}
+
+void Service::Init() {
+  if (FLAG_log_service_response_sizes == nullptr) {
+    return;
+  }
+  Dart_FileOpenCallback file_open = Dart::file_open_callback();
+  Dart_FileWriteCallback file_write = Dart::file_write_callback();
+  Dart_FileCloseCallback file_close = Dart::file_close_callback();
+  if ((file_open == nullptr) || (file_write == nullptr) ||
+      (file_close == nullptr)) {
+    OS::PrintErr("Error: Could not access file callbacks.");
+    UNREACHABLE();
+  }
+  ASSERT(service_response_size_log_file_ == nullptr);
+  service_response_size_log_file_ =
+      (*file_open)(FLAG_log_service_response_sizes, true);
+  if (service_response_size_log_file_ == nullptr) {
+    OS::PrintErr("Warning: Failed to open service response size log file: %s\n",
+                 FLAG_log_service_response_sizes);
+    return;
+  }
+}
+
+void Service::Cleanup() {
+  if (service_response_size_log_file_ == nullptr) {
+    return;
+  }
+  Dart_FileCloseCallback file_close = Dart::file_close_callback();
+  (*file_close)(service_response_size_log_file_);
+  service_response_size_log_file_ = nullptr;
+}
+
 static void PrintInvalidParamError(JSONStream* js, const char* param) {
 #if !defined(PRODUCT)
   js->PrintError(kInvalidParams, "%s: invalid '%s' parameter: %s", js->method(),
@@ -988,6 +1038,7 @@ ErrorPtr Service::InvokeMethod(Isolate* I,
         return T->StealStickyError();
       }
       method->entry(T, &js);
+      Service::LogResponseSize(c_method_name, &js);
       js.PostReply();
       return T->StealStickyError();
     }
@@ -1239,6 +1290,8 @@ void Service::PostEventImpl(Isolate* isolate,
     }
   }
 
+  Service::LogResponseSize(kind, event);
+
   // Message is of the format [<stream id>, <json string>].
   //
   // Build the event message in the C heap to avoid dart heap

runtime/vm/service.h

@@ -89,6 +89,9 @@ class StreamInfo {
 
 class Service : public AllStatic {
  public:
+  static void Init();
+  static void Cleanup();
+
   // Handles a message which is not directed to an isolate.
   static ErrorPtr HandleRootMessage(const Array& message);
 
@@ -159,6 +162,9 @@ class Service : public AllStatic {
                         const Instance& id,
                         const Error& error);
 
+  // Logs the size of the contents of `js` to FLAG_log_service_response_sizes.
+  static void LogResponseSize(const char* method, JSONStream* js);
+
   // Enable/Disable timeline categories.
   // Returns True if the categories were successfully enabled, False otherwise.
   static bool EnableTimelineStreams(char* categories_list);
@@ -250,6 +256,8 @@ class Service : public AllStatic {
   static Dart_GetVMServiceAssetsArchive get_service_assets_callback_;
   static Dart_EmbedderInformationCallback embedder_information_callback_;
 
+  static void* service_response_size_log_file_;
+
   static const uint8_t* dart_library_kernel_;
   static intptr_t dart_library_kernel_len_;
 };