From d2b2f17b1cfd33c7e00b9adaa6ac00153d5c3783 Mon Sep 17 00:00:00 2001 From: "Nathan.fooo" <86001920+appflowy@users.noreply.github.com> Date: Tue, 10 Dec 2024 10:02:48 +0800 Subject: [PATCH] chore: diagnose sync issues with sync.log file (#6950) * chore: filter sync log * chore: filter sync log * chore: enable/disable sync log * chore: enable/disable sync log * chore: observer document and folder * fix: integration test --------- Co-authored-by: Lucas.Xu --- .../desktop/cloud/cloud_runner.dart | 7 +-- .../lib/core/config/kv_keys.dart | 1 + .../appflowy_flutter/lib/env/backend_env.dart | 3 ++ .../appflowy_flutter/lib/env/cloud_env.dart | 21 +++++++++ .../settings/appflowy_cloud_setting_bloc.dart | 20 +++++++- .../application/sidebar/space/space_bloc.dart | 4 +- .../widgets/setting_appflowy_cloud.dart | 43 +++++++++++++++++ frontend/resources/translations/en.json | 4 +- frontend/rust-lib/Cargo.lock | 42 +++++++++++------ .../event-integration-test/src/user_event.rs | 1 + frontend/rust-lib/flowy-core/src/config.rs | 16 ++++++- .../rust-lib/flowy-document/src/document.rs | 17 +++++-- frontend/rust-lib/flowy-folder/src/manager.rs | 2 +- .../flowy-folder/src/manager_observer.rs | 9 +++- .../src/native/af_cloud_config.rs | 16 +++++++ frontend/rust-lib/lib-infra/src/util.rs | 10 ++++ frontend/rust-lib/lib-log/Cargo.toml | 4 +- frontend/rust-lib/lib-log/src/layer.rs | 35 +++++++++++--- frontend/rust-lib/lib-log/src/lib.rs | 46 ++++++++++++++----- 19 files changed, 252 insertions(+), 49 deletions(-) diff --git a/frontend/appflowy_flutter/integration_test/desktop/cloud/cloud_runner.dart b/frontend/appflowy_flutter/integration_test/desktop/cloud/cloud_runner.dart index 621baff5d0..a0b6901f2d 100644 --- a/frontend/appflowy_flutter/integration_test/desktop/cloud/cloud_runner.dart +++ b/frontend/appflowy_flutter/integration_test/desktop/cloud/cloud_runner.dart @@ -1,16 +1,17 @@ +import 'data_migration/data_migration_test_runner.dart' + as data_migration_test_runner; import 'document/document_test_runner.dart' as document_test_runner; +import 'set_env.dart' as preset_af_cloud_env_test; import 'sidebar/sidebar_move_page_test.dart' as sidebar_move_page_test; import 'uncategorized/uncategorized_test_runner.dart' as uncategorized_test_runner; import 'workspace/workspace_test_runner.dart' as workspace_test_runner; -import 'data_migration/data_migration_test_runner.dart' - as data_migration_test_runner; -import 'set_env.dart' as preset_af_cloud_env_test; Future main() async { preset_af_cloud_env_test.main(); data_migration_test_runner.main(); + // uncategorized uncategorized_test_runner.main(); diff --git a/frontend/appflowy_flutter/lib/core/config/kv_keys.dart b/frontend/appflowy_flutter/lib/core/config/kv_keys.dart index 1d76e329b7..c0e7f63f6c 100644 --- a/frontend/appflowy_flutter/lib/core/config/kv_keys.dart +++ b/frontend/appflowy_flutter/lib/core/config/kv_keys.dart @@ -58,6 +58,7 @@ class KVKeys { static const String kCloudType = 'kCloudType'; static const String kAppflowyCloudBaseURL = 'kAppFlowyCloudBaseURL'; + static const String kAppFlowyEnableSyncTrace = 'kAppFlowyEnableSyncTrace'; /// The key for saving the text scale factor. /// diff --git a/frontend/appflowy_flutter/lib/env/backend_env.dart b/frontend/appflowy_flutter/lib/env/backend_env.dart index f8aa715a40..a3f45f9f60 100644 --- a/frontend/appflowy_flutter/lib/env/backend_env.dart +++ b/frontend/appflowy_flutter/lib/env/backend_env.dart @@ -39,6 +39,7 @@ class AppFlowyCloudConfiguration { required this.base_url, required this.ws_base_url, required this.gotrue_url, + required this.enable_sync_trace, }); factory AppFlowyCloudConfiguration.fromJson(Map json) => @@ -47,6 +48,7 @@ class AppFlowyCloudConfiguration { final String base_url; final String ws_base_url; final String gotrue_url; + final bool enable_sync_trace; Map toJson() => _$AppFlowyCloudConfigurationToJson(this); @@ -55,6 +57,7 @@ class AppFlowyCloudConfiguration { base_url: '', ws_base_url: '', gotrue_url: '', + enable_sync_trace: false, ); } diff --git a/frontend/appflowy_flutter/lib/env/cloud_env.dart b/frontend/appflowy_flutter/lib/env/cloud_env.dart index 83a5288359..86b9636a93 100644 --- a/frontend/appflowy_flutter/lib/env/cloud_env.dart +++ b/frontend/appflowy_flutter/lib/env/cloud_env.dart @@ -212,6 +212,7 @@ class AppFlowyCloudSharedEnv { base_url: Env.afCloudUrl, ws_base_url: await _getAppFlowyCloudWSUrl(Env.afCloudUrl), gotrue_url: await _getAppFlowyCloudGotrueUrl(Env.afCloudUrl), + enable_sync_trace: false, ); return AppFlowyCloudSharedEnv( @@ -241,12 +242,14 @@ Future configurationFromUri( base_url: "$baseUrl:8000", ws_base_url: "ws://${baseUri.host}:8000/ws/v1", gotrue_url: "$baseUrl:9999", + enable_sync_trace: true, ); } else { return AppFlowyCloudConfiguration( base_url: baseUrl, ws_base_url: await _getAppFlowyCloudWSUrl(baseUrl), gotrue_url: await _getAppFlowyCloudGotrueUrl(baseUrl), + enable_sync_trace: await getSyncLogEnabled(), ); } } @@ -271,6 +274,24 @@ Future getAppFlowyCloudUrl() async { return result ?? kAppflowyCloudUrl; } +Future getSyncLogEnabled() async { + final result = + await getIt().get(KVKeys.kAppFlowyEnableSyncTrace); + + if (result == null) { + return false; + } + + return result.toLowerCase() == "true"; +} + +Future setSyncLogEnabled(bool enable) async { + await getIt().set( + KVKeys.kAppFlowyEnableSyncTrace, + enable.toString().toLowerCase(), + ); +} + Future _getAppFlowyCloudWSUrl(String baseURL) async { try { final uri = Uri.parse(baseURL); diff --git a/frontend/appflowy_flutter/lib/workspace/application/settings/appflowy_cloud_setting_bloc.dart b/frontend/appflowy_flutter/lib/workspace/application/settings/appflowy_cloud_setting_bloc.dart index fdb53f4e43..febb89727a 100644 --- a/frontend/appflowy_flutter/lib/workspace/application/settings/appflowy_cloud_setting_bloc.dart +++ b/frontend/appflowy_flutter/lib/workspace/application/settings/appflowy_cloud_setting_bloc.dart @@ -1,3 +1,4 @@ +import 'package:appflowy/env/cloud_env.dart'; import 'package:appflowy/generated/locale_keys.g.dart'; import 'package:appflowy/workspace/application/settings/cloud_setting_listener.dart'; import 'package:appflowy_backend/dispatch/dispatch.dart'; @@ -14,7 +15,7 @@ class AppFlowyCloudSettingBloc extends Bloc { AppFlowyCloudSettingBloc(CloudSettingPB setting) : _listener = UserCloudConfigListener(), - super(AppFlowyCloudSettingState.initial(setting)) { + super(AppFlowyCloudSettingState.initial(setting, false)) { _dispatch(); } @@ -31,6 +32,10 @@ class AppFlowyCloudSettingBloc (event, emit) async { await event.when( initial: () async { + await getSyncLogEnabled().then((value) { + emit(state.copyWith(isSyncLogEnabled: value)); + }); + _listener.start( onSettingChanged: (result) { if (isClosed) { @@ -48,6 +53,10 @@ class AppFlowyCloudSettingBloc final config = UpdateCloudConfigPB.create()..enableSync = isEnable; await UserEventSetCloudConfig(config).send(); }, + enableSyncLog: (isEnable) async { + await setSyncLogEnabled(isEnable); + emit(state.copyWith(isSyncLogEnabled: isEnable)); + }, didReceiveSetting: (CloudSettingPB setting) { emit( state.copyWith( @@ -67,6 +76,8 @@ class AppFlowyCloudSettingEvent with _$AppFlowyCloudSettingEvent { const factory AppFlowyCloudSettingEvent.initial() = _Initial; const factory AppFlowyCloudSettingEvent.enableSync(bool isEnable) = _EnableSync; + const factory AppFlowyCloudSettingEvent.enableSyncLog(bool isEnable) = + _EnableSyncLog; const factory AppFlowyCloudSettingEvent.didReceiveSetting( CloudSettingPB setting, ) = _DidUpdateSetting; @@ -77,12 +88,17 @@ class AppFlowyCloudSettingState with _$AppFlowyCloudSettingState { const factory AppFlowyCloudSettingState({ required CloudSettingPB setting, required bool showRestartHint, + required bool isSyncLogEnabled, }) = _AppFlowyCloudSettingState; - factory AppFlowyCloudSettingState.initial(CloudSettingPB setting) => + factory AppFlowyCloudSettingState.initial( + CloudSettingPB setting, + bool isSyncLogEnabled, + ) => AppFlowyCloudSettingState( setting: setting, showRestartHint: setting.serverUrl.isNotEmpty, + isSyncLogEnabled: isSyncLogEnabled, ); } diff --git a/frontend/appflowy_flutter/lib/workspace/application/sidebar/space/space_bloc.dart b/frontend/appflowy_flutter/lib/workspace/application/sidebar/space/space_bloc.dart index e1a825d631..0f1dc4e987 100644 --- a/frontend/appflowy_flutter/lib/workspace/application/sidebar/space/space_bloc.dart +++ b/frontend/appflowy_flutter/lib/workspace/application/sidebar/space/space_bloc.dart @@ -102,7 +102,9 @@ class SpaceBloc extends Bloc { if (openFirstPage) { if (currentSpace != null) { - add(SpaceEvent.open(currentSpace)); + if (!isClosed) { + add(SpaceEvent.open(currentSpace)); + } } } }, diff --git a/frontend/appflowy_flutter/lib/workspace/presentation/settings/widgets/setting_appflowy_cloud.dart b/frontend/appflowy_flutter/lib/workspace/presentation/settings/widgets/setting_appflowy_cloud.dart index 081cb88f5f..d99a6cbf01 100644 --- a/frontend/appflowy_flutter/lib/workspace/presentation/settings/widgets/setting_appflowy_cloud.dart +++ b/frontend/appflowy_flutter/lib/workspace/presentation/settings/widgets/setting_appflowy_cloud.dart @@ -68,6 +68,7 @@ class AppFlowyCloudViewSetting extends StatelessWidget { return Column( children: [ const AppFlowyCloudEnableSync(), + const AppFlowyCloudSyncLogEnabled(), const VSpace(12), RestartButton( onClick: () { @@ -123,6 +124,7 @@ class CustomAppFlowyCloudView extends StatelessWidget { final List children = []; children.addAll([ const AppFlowyCloudEnableSync(), + const AppFlowyCloudSyncLogEnabled(), const VSpace(40), ]); @@ -331,6 +333,47 @@ class AppFlowyCloudEnableSync extends StatelessWidget { } } +class AppFlowyCloudSyncLogEnabled extends StatelessWidget { + const AppFlowyCloudSyncLogEnabled({super.key}); + + @override + Widget build(BuildContext context) { + return BlocBuilder( + builder: (context, state) { + return Row( + children: [ + FlowyText.medium(LocaleKeys.settings_menu_enableSyncLog.tr()), + const Spacer(), + Toggle( + value: state.isSyncLogEnabled, + onChanged: (value) { + if (value) { + showCancelAndConfirmDialog( + context: context, + title: LocaleKeys.settings_menu_enableSyncLog.tr(), + description: + LocaleKeys.settings_menu_enableSyncLogWarning.tr(), + confirmLabel: LocaleKeys.button_confirm.tr(), + onConfirm: () { + context + .read() + .add(AppFlowyCloudSettingEvent.enableSyncLog(value)); + }, + ); + } else { + context + .read() + .add(AppFlowyCloudSettingEvent.enableSyncLog(value)); + } + }, + ), + ], + ); + }, + ); + } +} + class BillingGateGuard extends StatelessWidget { const BillingGateGuard({required this.builder, super.key}); diff --git a/frontend/resources/translations/en.json b/frontend/resources/translations/en.json index 8b1d97dba5..828114bf13 100644 --- a/frontend/resources/translations/en.json +++ b/frontend/resources/translations/en.json @@ -1036,6 +1036,8 @@ "syncSetting": "Sync Setting", "cloudSettings": "Cloud Settings", "enableSync": "Enable sync", + "enableSyncLog": "Enable sync logging", + "enableSyncLogWarning": "Thank you for helping diagnose sync issues. This will log your document edits to a local file. Please quit and reopen the app after enabling", "enableEncrypt": "Encrypt data", "cloudURL": "Base URL", "invalidCloudURLScheme": "Invalid Scheme", @@ -2904,4 +2906,4 @@ "permissionDenied": "No permission to open this file", "unknownError": "File open failed" } -} +} \ No newline at end of file diff --git a/frontend/rust-lib/Cargo.lock b/frontend/rust-lib/Cargo.lock index f2df3b0c53..ac5f27c453 100644 --- a/frontend/rust-lib/Cargo.lock +++ b/frontend/rust-lib/Cargo.lock @@ -1388,7 +1388,7 @@ dependencies = [ "cssparser-macros", "dtoa-short", "itoa", - "phf 0.8.0", + "phf 0.11.2", "smallvec", ] @@ -4369,7 +4369,7 @@ version = "0.8.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "3dfb61232e34fcb633f43d12c58f83c1df82962dcdfa565a4e866ffc17dafe12" dependencies = [ - "phf_macros", + "phf_macros 0.8.0", "phf_shared 0.8.0", "proc-macro-hack", ] @@ -4389,6 +4389,7 @@ version = "0.11.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "ade2d8b8f33c7333b51bcf0428d37e217e9f32192ae4772156f65063b8ce03dc" dependencies = [ + "phf_macros 0.11.2", "phf_shared 0.11.2", ] @@ -4456,6 +4457,19 @@ dependencies = [ "syn 1.0.109", ] +[[package]] +name = "phf_macros" +version = "0.11.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3444646e286606587e49f3bcf1679b8cef1dc2c5ecc29ddacaffc305180d464b" +dependencies = [ + "phf_generator 0.11.2", + "phf_shared 0.11.2", + "proc-macro2", + "quote", + "syn 2.0.47", +] + [[package]] name = "phf_shared" version = "0.8.0" @@ -6589,9 +6603,9 @@ checksum = "b6bc1c9ce2b5135ac7f93c72918fc37feb872bdc6a5533a8b85eb4b86bfdae52" [[package]] name = "tracing" -version = "0.1.40" +version = "0.1.41" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c3523ab5a71916ccf420eebdf5521fcef02141234bbc0b8a49f2fdc4544364ef" +checksum = "784e0ac535deb450455cbfa28a6f0df145ea1bb7ae51b821cf5e7927fdcfbdd0" dependencies = [ "log", "pin-project-lite", @@ -6613,9 +6627,9 @@ dependencies = [ [[package]] name = "tracing-attributes" -version = "0.1.27" +version = "0.1.28" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "34704c8d6ebcbc939824180af020566b01a7c01f80641264eba0999f6c2b6be7" +checksum = "395ae124c09f9e6918a2310af6038fba074bcf474ac352496d5910dd59a2226d" dependencies = [ "proc-macro2", "quote", @@ -6624,9 +6638,9 @@ dependencies = [ [[package]] name = "tracing-bunyan-formatter" -version = "0.3.9" +version = "0.3.10" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b5c266b9ac83dedf0e0385ad78514949e6d89491269e7065bee51d2bb8ec7373" +checksum = "2d637245a0d8774bd48df6482e086c59a8b5348a910c3b0579354045a9d82411" dependencies = [ "ahash 0.8.6", "gethostname", @@ -6642,9 +6656,9 @@ dependencies = [ [[package]] name = "tracing-core" -version = "0.1.32" +version = "0.1.33" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "c06d3da6113f116aaee68e4d601191614c9053067f9ab7f6edbcb161237daa54" +checksum = "e672c95779cf947c5311f83787af4fa8fffd12fb27e4993211a84bdfd9610f9c" dependencies = [ "once_cell", "valuable", @@ -6674,9 +6688,9 @@ dependencies = [ [[package]] name = "tracing-serde" -version = "0.1.3" +version = "0.2.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "bc6b213177105856957181934e4920de57730fc69bf42c37ee5bb664d406d9e1" +checksum = "704b1aeb7be0d0a84fc9828cae51dab5970fee5088f83d1dd7ee6f6246fc6ff1" dependencies = [ "serde", "tracing-core", @@ -6684,9 +6698,9 @@ dependencies = [ [[package]] name = "tracing-subscriber" -version = "0.3.18" +version = "0.3.19" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "ad0f048c97dbd9faa9b7df56362b8ebcaa52adb06b498c050d2f4e32f90a7a8b" +checksum = "e8189decb5ac0fa7bc8b96b7cb9b2701d60d48805aca84a238004d665fcc4008" dependencies = [ "matchers", "nu-ansi-term", diff --git a/frontend/rust-lib/event-integration-test/src/user_event.rs b/frontend/rust-lib/event-integration-test/src/user_event.rs index b06242ba78..1b82d9b83c 100644 --- a/frontend/rust-lib/event-integration-test/src/user_event.rs +++ b/frontend/rust-lib/event-integration-test/src/user_event.rs @@ -444,6 +444,7 @@ pub async fn use_localhost_af_cloud() { base_url, ws_base_url, gotrue_url, + enable_sync_trace: true, maximum_upload_file_size_in_bytes: None, } .write_env(); diff --git a/frontend/rust-lib/flowy-core/src/config.rs b/frontend/rust-lib/flowy-core/src/config.rs index e4e8c004d1..5c962df53f 100644 --- a/frontend/rust-lib/flowy-core/src/config.rs +++ b/frontend/rust-lib/flowy-core/src/config.rs @@ -40,6 +40,7 @@ impl fmt::Debug for AppFlowyCoreConfig { debug.field("base_url", &config.base_url); debug.field("ws_url", &config.ws_base_url); debug.field("gotrue_url", &config.gotrue_url); + debug.field("enable_sync_trace", &config.enable_sync_trace); } debug.finish() } @@ -83,11 +84,22 @@ impl AppFlowyCoreConfig { name: String, ) -> Self { let cloud_config = AFCloudConfiguration::from_env().ok(); + let mut log_crates = vec![]; let storage_path = match &cloud_config { None => custom_application_path, - Some(config) => make_user_data_folder(&custom_application_path, &config.base_url), + Some(config) => { + if config.enable_sync_trace { + log_crates.push("sync_trace_log".to_string()); + } + make_user_data_folder(&custom_application_path, &config.base_url) + }, }; - let log_filter = create_log_filter("info".to_owned(), vec![], OperatingSystem::from(&platform)); + + let log_filter = create_log_filter( + "info".to_owned(), + log_crates, + OperatingSystem::from(&platform), + ); AppFlowyCoreConfig { app_version, diff --git a/frontend/rust-lib/flowy-document/src/document.rs b/frontend/rust-lib/flowy-document/src/document.rs index da0007fbd9..ffdd0c900e 100644 --- a/frontend/rust-lib/flowy-document/src/document.rs +++ b/frontend/rust-lib/flowy-document/src/document.rs @@ -5,12 +5,17 @@ use crate::notification::{document_notification_builder, DocumentNotification}; use collab::preclude::Collab; use collab_document::document::Document; use futures::StreamExt; +use lib_infra::sync_trace; pub fn subscribe_document_changed(doc_id: &str, document: &mut Document) { let doc_id_clone_for_block_changed = doc_id.to_owned(); document.subscribe_block_changed("key", move |events, is_remote| { - #[cfg(feature = "verbose_log")] - tracing::trace!("subscribe_document_changed: {:?}", events); + sync_trace!( + "[Document] block changed in doc_id: {}, is_remote: {}, events: {:?}", + doc_id_clone_for_block_changed, + is_remote, + events + ); // send notification to the client. document_notification_builder( @@ -23,8 +28,12 @@ pub fn subscribe_document_changed(doc_id: &str, document: &mut Document) { let doc_id_clone_for_awareness_state = doc_id.to_owned(); document.subscribe_awareness_state("key", move |events| { - #[cfg(feature = "verbose_log")] - tracing::trace!("subscribe_awareness_state: {:?}", events); + sync_trace!( + "[Document] awareness state in doc_id: {}, events: {:?}", + doc_id_clone_for_awareness_state, + events + ); + document_notification_builder( &doc_id_clone_for_awareness_state, DocumentNotification::DidUpdateDocumentAwarenessState, diff --git a/frontend/rust-lib/flowy-folder/src/manager.rs b/frontend/rust-lib/flowy-folder/src/manager.rs index dcf8a7fdd8..6abc99229e 100644 --- a/frontend/rust-lib/flowy-folder/src/manager.rs +++ b/frontend/rust-lib/flowy-folder/src/manager.rs @@ -1188,7 +1188,7 @@ impl FolderManager { if let Some(view) = &view { let view_layout: ViewLayout = view.layout.clone().into(); if let Some(handle) = self.operation_handlers.get(&view_layout) { - info!("Open view: {}", view.id); + info!("Open view: {}-{}", view.name, view.id); if let Err(err) = handle.open_view(&view_id).await { error!("Open view error: {:?}", err); } diff --git a/frontend/rust-lib/flowy-folder/src/manager_observer.rs b/frontend/rust-lib/flowy-folder/src/manager_observer.rs index 12069e7317..dec4ff062d 100644 --- a/frontend/rust-lib/flowy-folder/src/manager_observer.rs +++ b/frontend/rust-lib/flowy-folder/src/manager_observer.rs @@ -10,6 +10,7 @@ use collab_folder::{ Folder, SectionChange, SectionChangeReceiver, TrashSectionChange, View, ViewChange, ViewChangeReceiver, }; +use lib_infra::sync_trace; use std::collections::HashSet; use std::sync::Weak; @@ -45,10 +46,14 @@ pub(crate) fn subscribe_folder_view_changed( ChildViewChangeReason::Create, ); let folder = lock.read().await; - notify_parent_view_did_change(&workspace_id, &folder, vec![view.parent_view_id]); + let parent_view_id = view.parent_view_id.clone(); + notify_parent_view_did_change(&workspace_id, &folder, vec![parent_view_id]); + sync_trace!("[Folder] create view: {:?}", view); }, ViewChange::DidDeleteView { views } => { for view in views { + sync_trace!("[Folder] delete view: {:?}", view); + notify_child_views_changed( view_pb_without_child_views(view.as_ref().clone()), ChildViewChangeReason::Delete, @@ -56,6 +61,8 @@ pub(crate) fn subscribe_folder_view_changed( } }, ViewChange::DidUpdate { view } => { + sync_trace!("[Folder] update view: {:?}", view); + notify_view_did_change(view.clone()); notify_child_views_changed( view_pb_without_child_views(view.clone()), diff --git a/frontend/rust-lib/flowy-server-pub/src/native/af_cloud_config.rs b/frontend/rust-lib/flowy-server-pub/src/native/af_cloud_config.rs index 690ea7c3f3..14a72c6ce6 100644 --- a/frontend/rust-lib/flowy-server-pub/src/native/af_cloud_config.rs +++ b/frontend/rust-lib/flowy-server-pub/src/native/af_cloud_config.rs @@ -7,6 +7,7 @@ use flowy_error::{ErrorCode, FlowyError}; pub const APPFLOWY_CLOUD_BASE_URL: &str = "APPFLOWY_CLOUD_ENV_APPFLOWY_CLOUD_BASE_URL"; pub const APPFLOWY_CLOUD_WS_BASE_URL: &str = "APPFLOWY_CLOUD_ENV_APPFLOWY_CLOUD_WS_BASE_URL"; pub const APPFLOWY_CLOUD_GOTRUE_URL: &str = "APPFLOWY_CLOUD_ENV_APPFLOWY_CLOUD_GOTRUE_URL"; +pub const APPFLOWY_ENABLE_SYNC_TRACE: &str = "APPFLOWY_ENABLE_SYNC_TRACE"; #[derive(Debug, Serialize, Deserialize, Clone, Default)] pub struct AFCloudConfiguration { @@ -14,6 +15,8 @@ pub struct AFCloudConfiguration { pub ws_base_url: String, pub gotrue_url: String, #[serde(default)] + pub enable_sync_trace: bool, + #[serde(default)] pub maximum_upload_file_size_in_bytes: Option, } @@ -55,10 +58,15 @@ impl AFCloudConfiguration { ); } + let enable_sync_trace = std::env::var(APPFLOWY_ENABLE_SYNC_TRACE) + .map(|v| v == "true" || v == "1") + .unwrap_or(false); + Ok(Self { base_url, ws_base_url, gotrue_url, + enable_sync_trace, maximum_upload_file_size_in_bytes: None, }) } @@ -68,5 +76,13 @@ impl AFCloudConfiguration { std::env::set_var(APPFLOWY_CLOUD_BASE_URL, &self.base_url); std::env::set_var(APPFLOWY_CLOUD_WS_BASE_URL, &self.ws_base_url); std::env::set_var(APPFLOWY_CLOUD_GOTRUE_URL, &self.gotrue_url); + std::env::set_var( + APPFLOWY_ENABLE_SYNC_TRACE, + if self.enable_sync_trace { + "true" + } else { + "false" + }, + ); } } diff --git a/frontend/rust-lib/lib-infra/src/util.rs b/frontend/rust-lib/lib-infra/src/util.rs index b67646e4be..18ff068a73 100644 --- a/frontend/rust-lib/lib-infra/src/util.rs +++ b/frontend/rust-lib/lib-infra/src/util.rs @@ -1,3 +1,6 @@ +#[allow(unused_imports)] +use tracing::info; + #[macro_export] macro_rules! if_native { ($($item:item)*) => {$( @@ -136,3 +139,10 @@ pub fn get_operating_system() -> OperatingSystem { } } } + +#[macro_export] +macro_rules! sync_trace { + ($($arg:tt)*) => { + tracing::info!(target: "sync_trace_log", $($arg)*); + }; +} diff --git a/frontend/rust-lib/lib-log/Cargo.toml b/frontend/rust-lib/lib-log/Cargo.toml index 1b8ebcb2bc..4316192f71 100644 --- a/frontend/rust-lib/lib-log/Cargo.toml +++ b/frontend/rust-lib/lib-log/Cargo.toml @@ -6,8 +6,8 @@ edition = "2018" # See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html [dependencies] -tracing-subscriber = { version = "0.3.17", features = ["registry", "env-filter", "ansi", "json"] } -tracing-bunyan-formatter = "0.3.9" +tracing-subscriber = { version = "0.3.19", features = ["registry", "env-filter", "ansi", "json"] } +tracing-bunyan-formatter = "0.3.10" tracing-appender = "0.2.3" tracing-core = "0.1" tracing.workspace = true diff --git a/frontend/rust-lib/lib-log/src/layer.rs b/frontend/rust-lib/lib-log/src/layer.rs index 28bd54b01f..945db52a8b 100644 --- a/frontend/rust-lib/lib-log/src/layer.rs +++ b/frontend/rust-lib/lib-log/src/layer.rs @@ -7,6 +7,7 @@ use tracing::{Event, Id, Subscriber}; use tracing_bunyan_formatter::JsonStorage; use tracing_core::metadata::Level; use tracing_core::span::Attributes; +use tracing_core::Metadata; use tracing_subscriber::{fmt::MakeWriter, layer::Context, registry::SpanRef, Layer}; const LEVEL: &str = "level"; @@ -22,6 +23,8 @@ const IGNORE_FIELDS: [&str; 2] = [LOG_MODULE_PATH, LOG_TARGET_PATH]; pub struct FlowyFormattingLayer<'a, W: MakeWriter<'static> + 'static> { make_writer: W, with_target: bool, + #[allow(clippy::type_complexity)] + target_filter: Option bool + Send + Sync>>, phantom: std::marker::PhantomData<&'a ()>, } @@ -34,10 +37,26 @@ where Self { make_writer, with_target: true, + target_filter: None, phantom: std::marker::PhantomData, } } + pub fn with_target_filter(mut self, filter: F) -> Self + where + F: Fn(&str) -> bool + Send + Sync + 'static, + { + self.target_filter = Some(Box::new(filter)); + self + } + + fn should_log(&self, metadata: &Metadata<'_>) -> bool { + self + .target_filter + .as_ref() + .map_or(true, |f| f(metadata.target())) + } + fn serialize_fields( &self, map_serializer: &mut impl SerializeMap, @@ -45,7 +64,6 @@ where _level: &Level, ) -> Result<(), std::io::Error> { map_serializer.serialize_entry(MESSAGE, &message)?; - // map_serializer.serialize_entry(LEVEL, &format!("{}", level))?; map_serializer.serialize_entry(TIME, &Local::now().format("%m-%d %H:%M:%S").to_string())?; Ok(()) } @@ -160,6 +178,10 @@ where W: for<'writer> MakeWriter<'writer> + 'static, { fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) { + if !self.should_log(event.metadata()) { + return; + } + // Events do not necessarily happen in the context of a span, hence // lookup_current returns an `Option>` instead of a // `SpanRef<_>`. @@ -177,14 +199,9 @@ where let message = format_event_message(¤t_span, event, &event_visitor, &ctx); self.serialize_fields(&mut map_serializer, &message, event.metadata().level())?; - // Additional metadata useful for debugging - // They should be nested under `src` (see https://github.com/trentm/node-bunyan#src ) - // but `tracing` does not support nested values yet - if self.with_target { map_serializer.serialize_entry("target", event.metadata().target())?; } - // map_serializer.serialize_entry("line", &event.metadata().line())?; // map_serializer.serialize_entry("file", &event.metadata().file())?; @@ -224,6 +241,9 @@ where fn on_new_span(&self, _attrs: &Attributes, id: &Id, ctx: Context<'_, S>) { let span = ctx.span(id).expect("Span not found, this is a bug"); + if !self.should_log(span.metadata()) { + return; + } if let Ok(serialized) = self.serialize_span(&span, Type::EnterSpan, &ctx) { let _ = self.emit(serialized); } @@ -231,6 +251,9 @@ where fn on_close(&self, id: Id, ctx: Context<'_, S>) { let span = ctx.span(&id).expect("Span not found, this is a bug"); + if !self.should_log(span.metadata()) { + return; + } if let Ok(serialized) = self.serialize_span(&span, Type::ExitSpan, &ctx) { let _ = self.emit(serialized); } diff --git a/frontend/rust-lib/lib-log/src/lib.rs b/frontend/rust-lib/lib-log/src/lib.rs index ee5bcd8f89..07145b27ff 100644 --- a/frontend/rust-lib/lib-log/src/lib.rs +++ b/frontend/rust-lib/lib-log/src/lib.rs @@ -2,6 +2,8 @@ use std::io; use std::io::Write; use std::sync::{Arc, RwLock}; +use crate::layer::FlowyFormattingLayer; +use crate::stream_log::{StreamLog, StreamLogSender}; use chrono::Local; use lazy_static::lazy_static; use lib_infra::util::OperatingSystem; @@ -13,26 +15,26 @@ use tracing_subscriber::fmt::format::Writer; use tracing_subscriber::fmt::MakeWriter; use tracing_subscriber::{layer::SubscriberExt, EnvFilter}; -use crate::layer::FlowyFormattingLayer; -use crate::stream_log::{StreamLog, StreamLogSender}; - mod layer; pub mod stream_log; lazy_static! { - static ref LOG_GUARD: RwLock> = RwLock::new(None); + static ref APP_LOG_GUARD: RwLock> = RwLock::new(None); + static ref COLLAB_SYNC_LOG_GUARD: RwLock> = RwLock::new(None); } pub struct Builder { #[allow(dead_code)] name: String, env_filter: String, - file_appender: RollingFileAppender, + app_log_appender: RollingFileAppender, + sync_log_appender: RollingFileAppender, #[allow(dead_code)] platform: OperatingSystem, stream_log_sender: Option>, } +const SYNC_TARGET: &str = "sync_trace_log"; impl Builder { pub fn new( name: &str, @@ -40,17 +42,26 @@ impl Builder { platform: &OperatingSystem, stream_log_sender: Option>, ) -> Self { - let file_appender = RollingFileAppender::builder() + let app_log_appender = RollingFileAppender::builder() .rotation(Rotation::DAILY) .filename_prefix(name) .max_log_files(6) .build(directory) .unwrap_or(tracing_appender::rolling::daily(directory, name)); + let sync_log_name = "log.sync"; + let sync_log_appender = RollingFileAppender::builder() + .rotation(Rotation::HOURLY) + .filename_prefix(sync_log_name) + .max_log_files(24) + .build(directory) + .unwrap_or(tracing_appender::rolling::hourly(directory, sync_log_name)); + Builder { name: name.to_owned(), env_filter: "info".to_owned(), - file_appender, + app_log_appender, + sync_log_appender, platform: platform.clone(), stream_log_sender, } @@ -63,8 +74,18 @@ impl Builder { pub fn build(self) -> Result<(), String> { let env_filter = EnvFilter::new(self.env_filter); - let (non_blocking, guard) = tracing_appender::non_blocking(self.file_appender); - let file_layer = FlowyFormattingLayer::new(non_blocking); + let (appflowy_log_non_blocking, app_log_guard) = + tracing_appender::non_blocking(self.app_log_appender); + *APP_LOG_GUARD.write().unwrap() = Some(app_log_guard); + let app_file_layer = FlowyFormattingLayer::new(appflowy_log_non_blocking) + .with_target_filter(|target| target != SYNC_TARGET); + + let (sync_log_non_blocking, sync_log_guard) = + tracing_appender::non_blocking(self.sync_log_appender); + *COLLAB_SYNC_LOG_GUARD.write().unwrap() = Some(sync_log_guard); + + let collab_sync_file_layer = FlowyFormattingLayer::new(sync_log_non_blocking) + .with_target_filter(|target| target == SYNC_TARGET); if let Some(stream_log_sender) = &self.stream_log_sender { let subscriber = tracing_subscriber::fmt() @@ -79,7 +100,8 @@ impl Builder { .with_env_filter(env_filter) .finish() .with(JsonStorageLayer) - .with(file_layer); + .with(app_file_layer) + .with(collab_sync_file_layer); set_global_default(subscriber).map_err(|e| format!("{:?}", e))?; } else { let subscriber = tracing_subscriber::fmt() @@ -92,11 +114,11 @@ impl Builder { .finish() .with(FlowyFormattingLayer::new(DebugStdoutWriter)) .with(JsonStorageLayer) - .with(file_layer); + .with(app_file_layer) + .with(collab_sync_file_layer); set_global_default(subscriber).map_err(|e| format!("{:?}", e))?; }; - *LOG_GUARD.write().unwrap() = Some(guard); Ok(()) } }