From b982eb62dce99c7d0284ba17130a573bb07b2ef9 Mon Sep 17 00:00:00 2001 From: Chris Bracken Date: Fri, 2 Apr 2021 14:25:33 -0700 Subject: [PATCH] Extract Dart logging to the embedders Previously messages logged from Dart code (e.g. via the print function) were handled directly in the engine by platform-specific code. This factors out a LogMessage(tag, message) callback that embedders can implement with platform-specific code. This also eliminates a dependency on platform-specific code in the core, and provides more flexibility to embedders than the current fallback to stdout, which can be a problem on platforms without a traditional stdout or with restrictions on stdout. Fixes https://github.com/flutter/flutter/issues/79685 --- common/settings.h | 8 +++ lib/ui/dart_runtime_hooks.cc | 57 +++++-------------- lib/ui/ui_dart_state.cc | 39 +++++++++++++ lib/ui/ui_dart_state.h | 10 ++++ runtime/dart_isolate.cc | 1 + shell/platform/android/flutter_main.cc | 8 +++ .../framework/Source/FlutterDartProject.mm | 17 ++++++ shell/platform/embedder/embedder.cc | 9 +++ shell/platform/embedder/embedder.h | 18 ++++++ shell/platform/embedder/fixtures/main.dart | 5 ++ .../embedder/tests/embedder_config_builder.cc | 6 ++ .../embedder/tests/embedder_config_builder.h | 2 + .../embedder/tests/embedder_test_context.cc | 14 +++++ .../embedder/tests/embedder_test_context.h | 7 +++ .../embedder/tests/embedder_unittests.cc | 19 +++++++ shell/platform/fuchsia/flutter/component.cc | 8 +++ shell/testing/tester_main.cc | 9 +++ 17 files changed, 194 insertions(+), 43 deletions(-) diff --git a/common/settings.h b/common/settings.h index 5dcef45a17ddb..d5304e47681f6 100644 --- a/common/settings.h +++ b/common/settings.h @@ -50,6 +50,9 @@ using TaskObserverRemove = std::function; using UnhandledExceptionCallback = std::function; +using LogMessageCallback = + std::function; // TODO(26783): Deprecate all the "path" struct members in favor of the // callback that generates the mapping from these paths. @@ -201,6 +204,11 @@ struct Settings { // managed thread and embedders must re-thread as necessary. Performing // blocking calls in this callback will cause applications to jank. UnhandledExceptionCallback unhandled_exception_callback; + // A callback given to the embedder to log print messages from the running + // Flutter application. This callback is made on an internal engine managed + // thread and embedders must re-thread if necessary. Performing blocking + // calls in this callback will cause applications to jank. + LogMessageCallback log_message_callback; bool enable_software_rendering = false; bool skia_deterministic_rendering_on_cpu = false; bool verbose_logging = false; diff --git a/lib/ui/dart_runtime_hooks.cc b/lib/ui/dart_runtime_hooks.cc index cb619aadc1a42..4eb06078ac60c 100644 --- a/lib/ui/dart_runtime_hooks.cc +++ b/lib/ui/dart_runtime_hooks.cc @@ -27,15 +27,6 @@ #include "third_party/tonic/scopes/dart_api_scope.h" #include "third_party/tonic/scopes/dart_isolate_scope.h" -#if defined(OS_ANDROID) -#include -#elif defined(OS_IOS) -extern "C" { -// Cannot import the syslog.h header directly because of macro collision. -extern void syslog(int, const char*, ...); -} -#endif - using tonic::DartConverter; using tonic::LogIfError; using tonic::ToDart; @@ -174,18 +165,8 @@ void Logger_PrintDebugString(Dart_NativeArguments args) { // Implementation of native functions which are used for some // test/debug functionality in standalone dart mode. void Logger_PrintString(Dart_NativeArguments args) { - std::stringstream stream; - const auto& logger_prefix = UIDartState::Current()->logger_prefix(); - -#if !OS_ANDROID - // Prepend all logs with the isolate debug name except on Android where that - // prefix is specified in the log tag. - if (logger_prefix.size() > 0) { - stream << logger_prefix << ": "; - } -#endif // !OS_ANDROID - - // Append the log buffer obtained from Dart code. + // Obtain the log buffer from Dart code. + std::string message; { Dart_Handle str = Dart_GetNativeArgument(args, 0); uint8_t* chars = nullptr; @@ -196,37 +177,27 @@ void Logger_PrintString(Dart_NativeArguments args) { return; } if (length > 0) { - stream << std::string{reinterpret_cast(chars), + message = std::string{reinterpret_cast(chars), static_cast(length)}; } } - const auto log_string = stream.str(); - const char* chars = log_string.c_str(); - const size_t length = log_string.size(); - - // Log using platform specific mechanisms - { -#if defined(OS_ANDROID) - // Write to the logcat on Android. - __android_log_print(ANDROID_LOG_INFO, logger_prefix.c_str(), "%.*s", - (int)length, chars); -#elif defined(OS_IOS) - // Write to syslog on iOS. - // - // TODO(cbracken): replace with dedicated communication channel and bypass - // iOS logging APIs altogether. - syslog(1 /* LOG_ALERT */, "%.*s", (int)length, chars); -#else - std::cout << log_string << std::endl; -#endif - } + const auto& tag = UIDartState::Current()->logger_prefix(); + UIDartState::Current()->LogMessage(tag, message); if (dart::bin::ShouldCaptureStdout()) { + std::stringstream stream; + if (tag.size() > 0) { + stream << tag << ": "; + } + stream << message; + std::string log = stream.str(); + // For now we report print output on the Stdout stream. uint8_t newline[] = {'\n'}; Dart_ServiceSendDataEvent("Stdout", "WriteEvent", - reinterpret_cast(chars), length); + reinterpret_cast(log.c_str()), + log.size()); Dart_ServiceSendDataEvent("Stdout", "WriteEvent", newline, sizeof(newline)); } } diff --git a/lib/ui/ui_dart_state.cc b/lib/ui/ui_dart_state.cc index 3def189206afc..2612cbe1fd88e 100644 --- a/lib/ui/ui_dart_state.cc +++ b/lib/ui/ui_dart_state.cc @@ -4,11 +4,22 @@ #include "flutter/lib/ui/ui_dart_state.h" +#include + #include "flutter/fml/message_loop.h" #include "flutter/lib/ui/window/platform_configuration.h" #include "third_party/tonic/converter/dart_converter.h" #include "third_party/tonic/dart_message_handler.h" +#if defined(OS_ANDROID) +#include +#elif defined(OS_IOS) +extern "C" { +// Cannot import the syslog.h header directly because of macro collision. +extern void syslog(int, const char*, ...); +} +#endif + using tonic::ToDart; namespace flutter { @@ -26,6 +37,7 @@ UIDartState::UIDartState( std::string advisory_script_entrypoint, std::string logger_prefix, UnhandledExceptionCallback unhandled_exception_callback, + LogMessageCallback log_message_callback, std::shared_ptr isolate_name_server, bool is_root_isolate, std::shared_ptr volatile_path_tracker, @@ -44,6 +56,7 @@ UIDartState::UIDartState( logger_prefix_(std::move(logger_prefix)), is_root_isolate_(is_root_isolate), unhandled_exception_callback_(unhandled_exception_callback), + log_message_callback_(log_message_callback), isolate_name_server_(std::move(isolate_name_server)), enable_skparagraph_(enable_skparagraph) { AddOrRemoveTaskObserver(true /* add */); @@ -187,6 +200,32 @@ void UIDartState::ReportUnhandledException(const std::string& error, << stack_trace; } +void UIDartState::LogMessage(const std::string& tag, + const std::string& message) const { + if (log_message_callback_) { + log_message_callback_(tag, message); + } else { + // Fall back to previous behavior if unspecified. +#if defined(OS_ANDROID) + __android_log_print(ANDROID_LOG_INFO, tag.c_str(), "%.*s", + (int)message.size(), message.c_str()); +#elif defined(OS_IOS) + std::stringstream stream; + if (tag.size() > 0) { + stream << tag << ": "; + } + stream << message; + std::string log = stream.str(); + syslog(1 /* LOG_ALERT */, "%.*s", (int)log.size(), log.c_str()); +#else + if (tag.size() > 0) { + std::cout << tag << ": "; + } + std::cout << message << std::endl; +#endif + } +} + bool UIDartState::enable_skparagraph() const { return enable_skparagraph_; } diff --git a/lib/ui/ui_dart_state.h b/lib/ui/ui_dart_state.h index 0a3e44a97ca78..636f32a12a973 100644 --- a/lib/ui/ui_dart_state.h +++ b/lib/ui/ui_dart_state.h @@ -77,6 +77,14 @@ class UIDartState : public tonic::DartState { void ReportUnhandledException(const std::string& error, const std::string& stack_trace); + // Logs `print` messages from the application via an embedder-specified + // logging mechanism. + // + // @param[in] tag A component name or tag that identifies the logging + // application. + // @param[in] message The message to be logged. + void LogMessage(const std::string& tag, const std::string& message) const; + bool enable_skparagraph() const; template @@ -103,6 +111,7 @@ class UIDartState : public tonic::DartState { std::string advisory_script_entrypoint, std::string logger_prefix, UnhandledExceptionCallback unhandled_exception_callback, + LogMessageCallback log_message_callback, std::shared_ptr isolate_name_server, bool is_root_isolate_, std::shared_ptr volatile_path_tracker, @@ -138,6 +147,7 @@ class UIDartState : public tonic::DartState { std::unique_ptr platform_configuration_; tonic::DartMicrotaskQueue microtask_queue_; UnhandledExceptionCallback unhandled_exception_callback_; + LogMessageCallback log_message_callback_; const std::shared_ptr isolate_name_server_; const bool enable_skparagraph_; diff --git a/runtime/dart_isolate.cc b/runtime/dart_isolate.cc index de933bca67fc4..cb1a4debf8f3e 100644 --- a/runtime/dart_isolate.cc +++ b/runtime/dart_isolate.cc @@ -331,6 +331,7 @@ DartIsolate::DartIsolate( advisory_script_entrypoint, settings.log_tag, settings.unhandled_exception_callback, + settings.log_message_callback, DartVMRef::GetIsolateNameServer(), is_root_isolate, std::move(volatile_path_tracker), diff --git a/shell/platform/android/flutter_main.cc b/shell/platform/android/flutter_main.cc index 1493bf4f0d161..35cf659488133 100644 --- a/shell/platform/android/flutter_main.cc +++ b/shell/platform/android/flutter_main.cc @@ -6,6 +6,8 @@ #include "flutter/shell/platform/android/flutter_main.h" +#include + #include #include "flutter/fml/command_line.h" @@ -107,6 +109,12 @@ void FlutterMain::Init(JNIEnv* env, fml::MessageLoop::GetCurrent().RemoveTaskObserver(key); }; + settings.log_message_callback = [](const std::string& tag, + const std::string& message) { + __android_log_print(ANDROID_LOG_INFO, tag.c_str(), "%.*s", + (int)message.size(), message.c_str()); + }; + #if FLUTTER_RUNTIME_MODE == FLUTTER_RUNTIME_MODE_DEBUG // There are no ownership concerns here as all mappings are owned by the // embedder and not the engine. diff --git a/shell/platform/darwin/ios/framework/Source/FlutterDartProject.mm b/shell/platform/darwin/ios/framework/Source/FlutterDartProject.mm index a034653487a84..2d650a773645a 100644 --- a/shell/platform/darwin/ios/framework/Source/FlutterDartProject.mm +++ b/shell/platform/darwin/ios/framework/Source/FlutterDartProject.mm @@ -6,6 +6,11 @@ #import "flutter/shell/platform/darwin/ios/framework/Source/FlutterDartProject_Internal.h" +#include + +#include +#include + #include "flutter/common/constants.h" #include "flutter/common/task_runners.h" #include "flutter/fml/mapping.h" @@ -57,6 +62,18 @@ fml::MessageLoop::GetCurrent().RemoveTaskObserver(key); }; + settings.log_message_callback = [](const std::string& tag, const std::string& message) { + // TODO(cbracken): replace this with os_log-based approach. + // https://github.com/flutter/flutter/issues/44030 + std::stringstream stream; + if (tag.size() > 0) { + stream << tag << ": "; + } + stream << message; + std::string log = stream.str(); + syslog(LOG_ALERT, "%.*s", (int)log.size(), log.c_str()); + }; + // The command line arguments may not always be complete. If they aren't, attempt to fill in // defaults. diff --git a/shell/platform/embedder/embedder.cc b/shell/platform/embedder/embedder.cc index 9c0b7ee2c3732..d03302dd6b5fb 100644 --- a/shell/platform/embedder/embedder.cc +++ b/shell/platform/embedder/embedder.cc @@ -953,6 +953,15 @@ FlutterEngineResult FlutterEngineInitialize(size_t version, settings.root_isolate_create_callback = [callback, user_data](const auto& isolate) { callback(user_data); }; } + if (SAFE_ACCESS(args, log_message_callback, nullptr) != nullptr) { + FlutterLogMessageCallback callback = + SAFE_ACCESS(args, log_message_callback, nullptr); + settings.log_message_callback = [callback, user_data]( + const std::string& tag, + const std::string& message) { + callback(tag.c_str(), message.c_str(), user_data); + }; + } flutter::PlatformViewEmbedder::UpdateSemanticsNodesCallback update_semantics_nodes_callback = nullptr; diff --git a/shell/platform/embedder/embedder.h b/shell/platform/embedder/embedder.h index d9badeea2afb8..39d817bacc793 100644 --- a/shell/platform/embedder/embedder.h +++ b/shell/platform/embedder/embedder.h @@ -1272,6 +1272,17 @@ typedef struct { }; } FlutterEngineAOTDataSource; +// Logging callback for Dart application messages. +// +// The `tag` parameter contains a null-terminated string containing a logging +// tag or component name that can be used to identify system log messages from +// the app. The `message` parameter contains a null-terminated string +// containing the message to be logged. `user_data` is a user data baton passed +// in `FlutterEngineRun`. +typedef void (*FlutterLogMessageCallback)(const char* /* tag */, + const char* /* message */, + void* /* user_data */); + /// An opaque object that describes the AOT data that can be used to launch a /// FlutterEngine instance in AOT mode. typedef struct _FlutterEngineAOTData* FlutterEngineAOTData; @@ -1495,6 +1506,13 @@ typedef struct { /// `FlutterProjectArgs`. const char* const* dart_entrypoint_argv; + // Logging callback for Dart application messages. + // + // This callback is used by embedder to log print messages from the running + // Flutter application. This callback is made on an internal engine managed + // thread and embedders must re-thread if necessary. Performing blocking calls + // in this callback may introduce application jank. + FlutterLogMessageCallback log_message_callback; } FlutterProjectArgs; #ifndef FLUTTER_ENGINE_NO_PROTOTYPES diff --git a/shell/platform/embedder/fixtures/main.dart b/shell/platform/embedder/fixtures/main.dart index 6c9290c82a32c..074515928839e 100644 --- a/shell/platform/embedder/fixtures/main.dart +++ b/shell/platform/embedder/fixtures/main.dart @@ -875,6 +875,11 @@ void render_targets_are_recycled() { void nativeArgumentsCallback(List args) native 'NativeArgumentsCallback'; +@pragma('vm:entry-point') +void custom_logger(List args) { + print("hello world"); +} + @pragma('vm:entry-point') void dart_entrypoint_args(List args) { nativeArgumentsCallback(args); diff --git a/shell/platform/embedder/tests/embedder_config_builder.cc b/shell/platform/embedder/tests/embedder_config_builder.cc index 37b2425136ebb..c8f5224c29771 100644 --- a/shell/platform/embedder/tests/embedder_config_builder.cc +++ b/shell/platform/embedder/tests/embedder_config_builder.cc @@ -99,6 +99,7 @@ EmbedderConfigBuilder::EmbedderConfigBuilder( SetAssetsPath(); SetIsolateCreateCallbackHook(); SetSemanticsCallbackHooks(); + SetLogMessageCallbackHook(); SetLocalizationCallbackHooks(); AddCommandLineArgument("--disable-observatory"); @@ -211,6 +212,11 @@ void EmbedderConfigBuilder::SetSemanticsCallbackHooks() { EmbedderTestContext::GetUpdateSemanticsCustomActionCallbackHook(); } +void EmbedderConfigBuilder::SetLogMessageCallbackHook() { + project_args_.log_message_callback = + EmbedderTestContext::GetLogMessageCallbackHook(); +} + void EmbedderConfigBuilder::SetLocalizationCallbackHooks() { project_args_.compute_platform_resolved_locale_callback = EmbedderTestContext::GetComputePlatformResolvedLocaleCallbackHook(); diff --git a/shell/platform/embedder/tests/embedder_config_builder.h b/shell/platform/embedder/tests/embedder_config_builder.h index b013002acfaf5..52aa44932a7c1 100644 --- a/shell/platform/embedder/tests/embedder_config_builder.h +++ b/shell/platform/embedder/tests/embedder_config_builder.h @@ -72,6 +72,8 @@ class EmbedderConfigBuilder { void SetSemanticsCallbackHooks(); + void SetLogMessageCallbackHook(); + void SetLocalizationCallbackHooks(); void SetDartEntrypoint(std::string entrypoint); diff --git a/shell/platform/embedder/tests/embedder_test_context.cc b/shell/platform/embedder/tests/embedder_test_context.cc index 71503ae4ef31a..2e322da0f96ec 100644 --- a/shell/platform/embedder/tests/embedder_test_context.cc +++ b/shell/platform/embedder/tests/embedder_test_context.cc @@ -140,6 +140,11 @@ void EmbedderTestContext::PlatformMessageCallback( } } +void EmbedderTestContext::SetLogMessageCallback( + const LogMessageCallback& callback) { + log_message_callback_ = callback; +} + FlutterUpdateSemanticsNodeCallback EmbedderTestContext::GetUpdateSemanticsNodeCallbackHook() { return [](const FlutterSemanticsNode* semantics_node, void* user_data) { @@ -160,6 +165,15 @@ EmbedderTestContext::GetUpdateSemanticsCustomActionCallbackHook() { }; } +FlutterLogMessageCallback EmbedderTestContext::GetLogMessageCallbackHook() { + return [](const char* tag, const char* message, void* user_data) { + auto context = reinterpret_cast(user_data); + if (auto callback = context->log_message_callback_) { + callback(tag, message); + } + }; +} + FlutterComputePlatformResolvedLocaleCallback EmbedderTestContext::GetComputePlatformResolvedLocaleCallbackHook() { return [](const FlutterLocale** supported_locales, diff --git a/shell/platform/embedder/tests/embedder_test_context.h b/shell/platform/embedder/tests/embedder_test_context.h index 39cbbc0c6290b..366b5b0b52cfe 100644 --- a/shell/platform/embedder/tests/embedder_test_context.h +++ b/shell/platform/embedder/tests/embedder_test_context.h @@ -27,6 +27,8 @@ namespace testing { using SemanticsNodeCallback = std::function; using SemanticsActionCallback = std::function; +using LogMessageCallback = + std::function; struct AOTDataDeleter { void operator()(FlutterEngineAOTData aot_data) { @@ -77,6 +79,8 @@ class EmbedderTestContext { void SetPlatformMessageCallback( const std::function& callback); + void SetLogMessageCallback(const LogMessageCallback& log_message_callback); + std::future> GetNextSceneImage(); EmbedderTestCompositor& GetCompositor(); @@ -104,6 +108,7 @@ class EmbedderTestContext { SemanticsNodeCallback update_semantics_node_callback_; SemanticsActionCallback update_semantics_custom_action_callback_; std::function platform_message_callback_; + LogMessageCallback log_message_callback_; std::unique_ptr compositor_; NextSceneCallback next_scene_callback_; SkMatrix root_surface_transformation_; @@ -116,6 +121,8 @@ class EmbedderTestContext { static FlutterUpdateSemanticsCustomActionCallback GetUpdateSemanticsCustomActionCallbackHook(); + static FlutterLogMessageCallback GetLogMessageCallbackHook(); + static FlutterComputePlatformResolvedLocaleCallback GetComputePlatformResolvedLocaleCallbackHook(); diff --git a/shell/platform/embedder/tests/embedder_unittests.cc b/shell/platform/embedder/tests/embedder_unittests.cc index 6175daa820dce..f418ab8f3684d 100644 --- a/shell/platform/embedder/tests/embedder_unittests.cc +++ b/shell/platform/embedder/tests/embedder_unittests.cc @@ -452,6 +452,25 @@ TEST_F(EmbedderTest, InvalidPlatformMessages) { ASSERT_EQ(result, kInvalidArguments); } +//------------------------------------------------------------------------------ +/// Tests that setting a custom log callback works as expected. +TEST_F(EmbedderTest, CanSetCustomLogMessageCallback) { + fml::AutoResetWaitableEvent callback_latch; + auto& context = GetEmbedderContext(EmbedderTestContextType::kSoftwareContext); + EmbedderConfigBuilder builder(context); + builder.SetDartEntrypoint("custom_logger"); + builder.SetSoftwareRendererConfig(); + context.SetLogMessageCallback( + [&callback_latch](const char* tag, const char* message) { + EXPECT_EQ(std::string(tag), "flutter"); + EXPECT_EQ(std::string(message), "hello world"); + callback_latch.Signal(); + }); + auto engine = builder.LaunchEngine(); + ASSERT_TRUE(engine.is_valid()); + callback_latch.Wait(); +} + //------------------------------------------------------------------------------ /// Asserts behavior of FlutterProjectArgs::shutdown_dart_vm_when_done (which is /// set to true by default in these unit-tests). diff --git a/shell/platform/fuchsia/flutter/component.cc b/shell/platform/fuchsia/flutter/component.cc index 5eeefe754e0dd..d73dc5d2f9554 100644 --- a/shell/platform/fuchsia/flutter/component.cc +++ b/shell/platform/fuchsia/flutter/component.cc @@ -497,6 +497,14 @@ Application::Application( settings_.task_observer_remove = std::bind( &CurrentMessageLoopRemoveAfterTaskObserver, std::placeholders::_1); + settings_.log_message_callback = [](const std::string& tag, + const std::string& message) { + if (tag.size() > 0) { + std::cout << tag << ": "; + } + std::cout << message << std::endl; + }; + settings_.dart_flags = {"--no_causal_async_stacks", "--lazy_async_stacks"}; // Don't collect CPU samples from Dart VM C++ code. diff --git a/shell/testing/tester_main.cc b/shell/testing/tester_main.cc index d775bc4c97170..6095ffe145eb2 100644 --- a/shell/testing/tester_main.cc +++ b/shell/testing/tester_main.cc @@ -6,6 +6,7 @@ #include #include +#include #include "flutter/assets/asset_manager.h" #include "flutter/assets/directory_asset_bundle.h" @@ -292,6 +293,14 @@ int main(int argc, char* argv[]) { // The tools that read logs get confused if there is a log tag specified. settings.log_tag = ""; + settings.log_message_callback = [](const std::string& tag, + const std::string& message) { + if (tag.size() > 0) { + std::cout << tag << ": "; + } + std::cout << message << std::endl; + }; + settings.task_observer_add = [](intptr_t key, fml::closure callback) { fml::MessageLoop::GetCurrent().AddTaskObserver(key, std::move(callback)); };