From e5353aa3ae4bcaa75cd0ac48a6e47035c57df942 Mon Sep 17 00:00:00 2001 From: Elias Yishak <42216813+eliasyishak@users.noreply.github.com> Date: Fri, 10 Mar 2023 16:35:44 -0500 Subject: [PATCH] Adding more information to `LogFileStats` + minor updates to tests (#31) * Adding duration for start and end times + record count * Update USAGE_GUIDE.md * Update to include counts for each event in LogFileStats * Update CHANGELOG.md * Use package:clock for LogFileStats calculations * Update to test to include newly added data points * Added test to check CHANGELOG for matching versions * Prep for publishing * Remove redundant expect statement * Ensure that no events are being sent for the first run + test * Fixing tests to account for no events sent on tool first run * Clean up from dart format * dart format on test directory * Use one clock for `now` * Including formatDateTime to include timezone offset * Updating documentation of `local_time` --- pkgs/unified_analytics/CHANGELOG.md | 3 +- pkgs/unified_analytics/USAGE_GUIDE.md | 22 +- pkgs/unified_analytics/lib/src/analytics.dart | 11 +- pkgs/unified_analytics/lib/src/constants.dart | 2 +- .../lib/src/log_handler.dart | 62 +++++- .../lib/src/user_property.dart | 3 +- pkgs/unified_analytics/lib/src/utils.dart | 17 +- pkgs/unified_analytics/pubspec.yaml | 2 +- .../test/unified_analytics_test.dart | 197 +++++++++++++----- 9 files changed, 251 insertions(+), 68 deletions(-) diff --git a/pkgs/unified_analytics/CHANGELOG.md b/pkgs/unified_analytics/CHANGELOG.md index 22bc52809..347a36a5d 100644 --- a/pkgs/unified_analytics/CHANGELOG.md +++ b/pkgs/unified_analytics/CHANGELOG.md @@ -1,6 +1,7 @@ -## 0.1.1-dev +## 0.1.1 - Bumping intl package to 0.18.0 to fix version solving issue with flutter_tools +- LogFileStats includes more information about how many events are persisted and total count of how many times each event was sent ## 0.1.0 diff --git a/pkgs/unified_analytics/USAGE_GUIDE.md b/pkgs/unified_analytics/USAGE_GUIDE.md index 104063778..ae1fca1bf 100644 --- a/pkgs/unified_analytics/USAGE_GUIDE.md +++ b/pkgs/unified_analytics/USAGE_GUIDE.md @@ -156,18 +156,30 @@ print(analytics.logFileStats()); // Prints out the below // { -// "startDateTime": "2023-02-08 15:07:10.293728", -// "endDateTime": "2023-02-08 15:07:10.299678", -// "sessionCount": 1, -// "flutterChannelCount": 1, -// "toolCount": 1 +// "startDateTime": "2023-02-22 15:23:24.410921", +// "minsFromStartDateTime": 20319, +// "endDateTime": "2023-03-08 15:46:36.318211", +// "minsFromEndDateTime": 136, +// "sessionCount": 7, +// "flutterChannelCount": 2, +// "toolCount": 1, +// "recordCount": 23, +// "eventCount": { +// "hot_reload_time": 16, +// "analytics_collection_enabled": 7, +// ... scales up with number of events +// } // } ``` Explanation of the each key above - startDateTime: the earliest event that was sent +- minsFromStartDateTime: the number of minutes elapsed since the earliest message - endDateTime: the latest, most recent event that was sent +- minsFromEndDateTime: the number of minutes elapsed since the latest message - sessionCount: count of sessions; sessions have a minimum time of 30 minutes - flutterChannelCount: count of flutter channels (can be 0 if developer is a Dart dev only) - toolCount: count of the Dart and Flutter tools sending analytics +- recordCount: count of the total number of events in the log file +- eventCount: counts each unique event and how many times they occurred in the log file \ No newline at end of file diff --git a/pkgs/unified_analytics/lib/src/analytics.dart b/pkgs/unified_analytics/lib/src/analytics.dart index 67a782c37..fa1f5102f 100644 --- a/pkgs/unified_analytics/lib/src/analytics.dart +++ b/pkgs/unified_analytics/lib/src/analytics.dart @@ -246,7 +246,14 @@ class AnalyticsImpl implements Analytics { required DashEvent eventName, Map eventData = const {}, }) { - if (!telemetryEnabled) return null; + // Checking the [telemetryEnabled] boolean reflects what the + // config file reflects + // + // Checking the [_showMessage] boolean indicates if this the first + // time the tool is using analytics or if there has been an update + // the messaging found in constants.dart - in both cases, analytics + // will not be sent until the second time the tool is used + if (!telemetryEnabled || _showMessage) return null; // Construct the body of the request final Map body = generateRequestBody( @@ -311,7 +318,7 @@ class TestAnalytics extends AnalyticsImpl { required DashEvent eventName, Map eventData = const {}, }) { - if (!telemetryEnabled) return null; + if (!telemetryEnabled || _showMessage) return null; // Calling the [generateRequestBody] method will ensure that the // session file is getting updated without actually making any diff --git a/pkgs/unified_analytics/lib/src/constants.dart b/pkgs/unified_analytics/lib/src/constants.dart index b1006f8e8..51155d00c 100644 --- a/pkgs/unified_analytics/lib/src/constants.dart +++ b/pkgs/unified_analytics/lib/src/constants.dart @@ -70,7 +70,7 @@ const int kLogFileLength = 2500; const String kLogFileName = 'dash-analytics.log'; /// The current version of the package, should be in line with pubspec version. -const String kPackageVersion = '0.1.1-dev'; +const String kPackageVersion = '0.1.1'; /// The minimum length for a session const int kSessionDurationMinutes = 30; diff --git a/pkgs/unified_analytics/lib/src/log_handler.dart b/pkgs/unified_analytics/lib/src/log_handler.dart index 872fe3139..2caf2b532 100644 --- a/pkgs/unified_analytics/lib/src/log_handler.dart +++ b/pkgs/unified_analytics/lib/src/log_handler.dart @@ -4,6 +4,7 @@ import 'dart:convert'; +import 'package:clock/clock.dart'; import 'package:file/file.dart'; import 'package:path/path.dart' as p; @@ -16,9 +17,15 @@ class LogFileStats { /// The oldest timestamp in the log file final DateTime startDateTime; + /// Number of minutes from [startDateTime] to [clock.now()] + final int minsFromStartDateTime; + /// The latest timestamp in the log file final DateTime endDateTime; + /// Number of minutes from [endDateTime] to [clock.now()] + final int minsFromEndDateTime; + /// The number of unique session ids found in the log file final int sessionCount; @@ -28,22 +35,37 @@ class LogFileStats { /// The number of unique tools found in the log file final int toolCount; + /// The map containing all of the events in the file along with + /// how many times they have occured + final Map eventCount; + + /// Total number of records in the log file + final int recordCount; + /// Contains the data from the [LogHandler.logFileStats] method const LogFileStats({ required this.startDateTime, + required this.minsFromStartDateTime, required this.endDateTime, + required this.minsFromEndDateTime, required this.sessionCount, required this.flutterChannelCount, required this.toolCount, + required this.recordCount, + required this.eventCount, }); @override String toString() => jsonEncode({ 'startDateTime': startDateTime.toString(), + 'minsFromStartDateTime': minsFromStartDateTime, 'endDateTime': endDateTime.toString(), + 'minsFromEndDateTime': minsFromEndDateTime, 'sessionCount': sessionCount, 'flutterChannelCount': flutterChannelCount, 'toolCount': toolCount, + 'recordCount': recordCount, + 'eventCount': eventCount, }); } @@ -89,26 +111,42 @@ class LogHandler { final DateTime startDateTime = records.first.localTime; final DateTime endDateTime = records.last.localTime; - // Collection of unique sessions + // Map with counters for user properties final Map> counter = >{ 'sessions': {}, 'flutter_channel': {}, 'tool': {}, }; + + // Map of counters for each event + final Map eventCount = {}; for (LogItem record in records) { counter['sessions']!.add(record.sessionId); counter['tool']!.add(record.tool); if (record.flutterChannel != null) { counter['flutter_channel']!.add(record.flutterChannel!); } + + // Count each event, if it doesn't exist in the [eventCount] + // it will be added first + if (!eventCount.containsKey(record.eventName)) { + eventCount[record.eventName] = 0; + } + eventCount[record.eventName] = eventCount[record.eventName]! + 1; } + final DateTime now = clock.now(); + return LogFileStats( startDateTime: startDateTime, + minsFromStartDateTime: now.difference(startDateTime).inMinutes, endDateTime: endDateTime, + minsFromEndDateTime: now.difference(endDateTime).inMinutes, sessionCount: counter['sessions']!.length, flutterChannelCount: counter['flutter_channel']!.length, toolCount: counter['tool']!.length, + eventCount: eventCount, + recordCount: records.length, ); } @@ -135,6 +173,7 @@ class LogHandler { /// Data class for each record persisted on the client's machine class LogItem { + final String eventName; final int sessionId; final String? flutterChannel; final String host; @@ -144,6 +183,7 @@ class LogItem { final DateTime localTime; LogItem({ + required this.eventName, required this.sessionId, this.flutterChannel, required this.host, @@ -194,18 +234,27 @@ class LogItem { /// "value": "flutter-tools" /// }, /// "local_time": { - /// "value": "2023-01-31 14:32:14.592898" + /// "value": "2023-01-31 14:32:14.592898 -0500" /// } /// } /// } /// ``` static LogItem? fromRecord(Map record) { - if (!record.containsKey('user_properties')) return null; + if (!record.containsKey('user_properties') || + !record.containsKey('events')) { + return null; + } // Using a try/except here to parse out the fields if possible, // if not, it will quietly return null and won't get processed // downstream try { + // Parse out values from the top level key = 'events' and return + // a map for the one event in the value + final Map eventProp = + ((record['events']! as List).first as Map); + final String eventName = eventProp['name'] as String; + // Parse the data out of the `user_properties` value final Map userProps = record['user_properties'] as Map; @@ -230,6 +279,10 @@ class LogItem { // indicates the record is malformed; note that `flutter_version` // and `flutter_channel` are nullable fields in the log file final List values = [ + // Values associated with the top level key = 'events' + eventName, + + // Values associated with the top level key = 'events' sessionId, host, dartVersion, @@ -241,9 +294,10 @@ class LogItem { } // Parse the local time from the string extracted - final DateTime localTime = DateTime.parse(localTimeString!); + final DateTime localTime = DateTime.parse(localTimeString!).toLocal(); return LogItem( + eventName: eventName, sessionId: sessionId!, flutterChannel: flutterChannel, host: host!, diff --git a/pkgs/unified_analytics/lib/src/user_property.dart b/pkgs/unified_analytics/lib/src/user_property.dart index ee82e6233..b85870e6d 100644 --- a/pkgs/unified_analytics/lib/src/user_property.dart +++ b/pkgs/unified_analytics/lib/src/user_property.dart @@ -8,6 +8,7 @@ import 'package:clock/clock.dart'; import 'constants.dart'; import 'session.dart'; +import 'utils.dart'; class UserProperty { final Session session; @@ -58,6 +59,6 @@ class UserProperty { 'dart_version': dartVersion, 'analytics_pkg_version': kPackageVersion, 'tool': tool, - 'local_time': '${clock.now()}', + 'local_time': formatDateTime(clock.now()), }; } diff --git a/pkgs/unified_analytics/lib/src/utils.dart b/pkgs/unified_analytics/lib/src/utils.dart index f007ecb15..e9b556247 100644 --- a/pkgs/unified_analytics/lib/src/utils.dart +++ b/pkgs/unified_analytics/lib/src/utils.dart @@ -10,6 +10,21 @@ import 'package:file/file.dart'; import 'enums.dart'; import 'user_property.dart'; +/// Format time as 'yyyy-MM-dd HH:mm:ss Z' where Z is the difference between the +/// timezone of t and UTC formatted according to RFC 822. +String formatDateTime(DateTime t) { + final String sign = t.timeZoneOffset.isNegative ? '-' : '+'; + final Duration tzOffset = t.timeZoneOffset.abs(); + final int hoursOffset = tzOffset.inHours; + final int minutesOffset = + tzOffset.inMinutes - (Duration.minutesPerHour * hoursOffset); + assert(hoursOffset < 24); + assert(minutesOffset < 60); + + String twoDigits(int n) => (n >= 10) ? '$n' : '0$n'; + return '$t $sign${twoDigits(hoursOffset)}${twoDigits(minutesOffset)}'; +} + /// Construct the Map that will be converted to json for the /// body of the request /// @@ -26,7 +41,7 @@ import 'user_property.dart'; /// "flutter_version": { "value": "Flutter 3.6.0-7.0.pre.47" }, /// "dart_version": { "value": "Dart 2.19.0" }, /// "tool": { "value": "flutter-tools" }, -/// "local_time": { "value": "2023-01-11 14:53:31.471816" } +/// "local_time": { "value": "2023-01-11 14:53:31.471816 -0500" } /// } /// } /// ``` diff --git a/pkgs/unified_analytics/pubspec.yaml b/pkgs/unified_analytics/pubspec.yaml index e5d0a16c8..7f1490268 100644 --- a/pkgs/unified_analytics/pubspec.yaml +++ b/pkgs/unified_analytics/pubspec.yaml @@ -4,7 +4,7 @@ description: >- to Google Analytics. # When updating this, keep the version consistent with the changelog and the # value in lib/src/constants.dart. -version: 0.1.1-dev +version: 0.1.1 repository: https://github.com/dart-lang/tools/tree/main/pkgs/unified_analytics environment: diff --git a/pkgs/unified_analytics/test/unified_analytics_test.dart b/pkgs/unified_analytics/test/unified_analytics_test.dart index 95ef536f1..ed2bd9ab2 100644 --- a/pkgs/unified_analytics/test/unified_analytics_test.dart +++ b/pkgs/unified_analytics/test/unified_analytics_test.dart @@ -22,6 +22,7 @@ void main() { late FileSystem fs; late Directory home; late Directory dartToolDirectory; + late Analytics initializationAnalytics; late Analytics analytics; late File clientIdFile; late File sessionFile; @@ -49,8 +50,27 @@ void main() { home = fs.directory(homeDirName); dartToolDirectory = home.childDirectory(kDartToolDirectoryName); + // This is the first analytics instance that will be used to demonstrate + // that events will not be sent with the first run of analytics + initializationAnalytics = Analytics.test( + tool: initialToolName, + homeDirectory: home, + measurementId: measurementId, + apiSecret: apiSecret, + flutterChannel: flutterChannel, + toolsMessageVersion: toolsMessageVersion, + toolsMessage: toolsMessage, + flutterVersion: flutterVersion, + dartVersion: dartVersion, + fs: fs, + platform: platform, + ); + // The main analytics instance, other instances can be spawned within tests // to test how to instances running together work + // + // This instance should have the same parameters as the one above for + // [initializationAnalytics] analytics = Analytics.test( tool: initialToolName, homeDirectory: home, @@ -102,7 +122,7 @@ void main() { expect(dartToolDirectory.listSync().length, equals(4), reason: 'There should only be 4 files in the $kDartToolDirectoryName directory'); - expect(analytics.shouldShowMessage, true, + expect(initializationAnalytics.shouldShowMessage, true, reason: 'For the first run, analytics should default to being enabled'); expect(configFile.readAsLinesSync().length, kConfigString.split('\n').length + 1, @@ -138,6 +158,24 @@ void main() { 'The config file should have the same message from the constants file'); }); + test('First time analytics run will not send events, second time will', () { + // Send an event with the first analytics class; this should result + // in no logs in the log file which keeps track of all the events + // that have been sent + initializationAnalytics.sendEvent( + eventName: DashEvent.hotReloadTime, eventData: {}); + initializationAnalytics.sendEvent( + eventName: DashEvent.hotReloadTime, eventData: {}); + + // Use the second instance of analytics defined in setUp() to send the actual + // events to simulate the second time the tool ran + analytics.sendEvent( + eventName: DashEvent.hotReloadTime, eventData: {}); + + expect(logFile.readAsLinesSync().length, 1, + reason: 'The second analytics instance should have logged an event'); + }); + test('Toggling telemetry boolean through Analytics class api', () async { expect(analytics.telemetryEnabled, true, reason: 'Telemetry should be enabled by default ' @@ -699,55 +737,96 @@ $initialToolName=${ConfigHandler.dateStamp},$toolsMessageVersion }); test('Check the query on the log file works as expected', () { - expect(analytics.logFileStats(), isNull, - reason: 'The result for the log file stats should be null when ' - 'there are no logs'); - analytics.sendEvent( - eventName: DashEvent.hotReloadTime, eventData: {}); + // Define a new clock so that we can check the output of the + // log file stats method explicitly + final DateTime start = DateTime(1995, 3, 3, 12, 0); + final Clock firstClock = Clock.fixed(start); - final LogFileStats firstQuery = analytics.logFileStats()!; - expect(firstQuery.sessionCount, 1, - reason: - 'There should only be one session after the initial send event'); - expect(firstQuery.flutterChannelCount, 1, - reason: 'There should only be one flutter channel logged'); - expect(firstQuery.toolCount, 1, - reason: 'There should only be one tool logged'); + // Run with the simulated clock for the initial events + withClock(firstClock, () { + expect(analytics.logFileStats(), isNull, + reason: 'The result for the log file stats should be null when ' + 'there are no logs'); + analytics.sendEvent( + eventName: DashEvent.hotReloadTime, eventData: {}); + + final LogFileStats firstQuery = analytics.logFileStats()!; + expect(firstQuery.sessionCount, 1, + reason: + 'There should only be one session after the initial send event'); + expect(firstQuery.flutterChannelCount, 1, + reason: 'There should only be one flutter channel logged'); + expect(firstQuery.toolCount, 1, + reason: 'There should only be one tool logged'); + }); // Define a new clock that is outside of the session duration - final DateTime firstClock = - clock.now().add(Duration(minutes: kSessionDurationMinutes + 1)); + final DateTime secondClock = + start.add(Duration(minutes: kSessionDurationMinutes + 1)); // Use the new clock to send an event that will change the session identifier - withClock(Clock.fixed(firstClock), () { + withClock(Clock.fixed(secondClock), () { analytics.sendEvent( eventName: DashEvent.hotReloadTime, eventData: {}); - }); - final LogFileStats secondQuery = analytics.logFileStats()!; - expect(secondQuery.sessionCount, 2, - reason: 'There should be 2 sessions after the second event'); + final LogFileStats secondQuery = analytics.logFileStats()!; + + // Construct the expected response for the second query + // + // This will need to be updated as the output for [LogFileStats] + // changes in the future + // + // Expecting the below returned + // { + // "startDateTime": "1995-03-03 12:00:00.000", + // "minsFromStartDateTime": 31, + // "endDateTime": "1995-03-03 12:31:00.000", + // "minsFromEndDateTime": 0, + // "sessionCount": 2, + // "flutterChannelCount": 1, + // "toolCount": 1, + // "recordCount": 2, + // "eventCount": { + // "hot_reload_time": 2 + // } + // } + expect(secondQuery.startDateTime, DateTime(1995, 3, 3, 12, 0)); + expect(secondQuery.minsFromStartDateTime, 31); + expect(secondQuery.endDateTime, DateTime(1995, 3, 3, 12, 31)); + expect(secondQuery.minsFromEndDateTime, 0); + expect(secondQuery.sessionCount, 2); + expect(secondQuery.flutterChannelCount, 1); + expect(secondQuery.toolCount, 1); + expect(secondQuery.recordCount, 2); + expect(secondQuery.eventCount, {'hot_reload_time': 2}); + }); }); test('Check that the log file shows two different tools being used', () { - final Analytics secondAnalytics = Analytics.test( - tool: secondTool, - homeDirectory: home, - measurementId: 'measurementId', - apiSecret: 'apiSecret', - flutterChannel: flutterChannel, - toolsMessageVersion: toolsMessageVersion, - toolsMessage: toolsMessage, - flutterVersion: 'Flutter 3.6.0-7.0.pre.47', - dartVersion: 'Dart 2.19.0', - fs: fs, - platform: platform, - ); + // Use a for loop two initialize the second analytics instance + // twice to account for no events being sent on the first instance + // run for a given tool + Analytics? secondAnalytics; + for (int i = 0; i < 2; i++) { + secondAnalytics = Analytics.test( + tool: secondTool, + homeDirectory: home, + measurementId: 'measurementId', + apiSecret: 'apiSecret', + flutterChannel: flutterChannel, + toolsMessageVersion: toolsMessageVersion, + toolsMessage: toolsMessage, + flutterVersion: 'Flutter 3.6.0-7.0.pre.47', + dartVersion: 'Dart 2.19.0', + fs: fs, + platform: platform, + ); + } // Send events with both instances of the classes analytics.sendEvent( eventName: DashEvent.hotReloadTime, eventData: {}); - secondAnalytics.sendEvent( + secondAnalytics!.sendEvent( eventName: DashEvent.hotReloadTime, eventData: {}); // Query the log file stats to verify that there are two tools @@ -769,7 +848,7 @@ $initialToolName=${ConfigHandler.dateStamp},$toolsMessageVersion '"flutter_version":{"value":"Flutter 3.6.0-7.0.pre.47"},' '"dart_version":{"value":"Dart 2.19.0"},' // '"tool":{"value":"flutter-tools"},' NEEDS REMAIN REMOVED - '"local_time":{"value":"2023-01-31 14:32:14.592898"}}}'; + '"local_time":{"value":"2023-01-31 14:32:14.592898 -0500"}}}'; logFile.writeAsStringSync(malformedLog); final LogFileStats? query = analytics.logFileStats(); @@ -791,7 +870,7 @@ $initialToolName=${ConfigHandler.dateStamp},$toolsMessageVersion '"flutter_version":{"value":"Flutter 3.6.0-7.0.pre.47"},' '"dart_version":{"value":"Dart 2.19.0"},' '"tool":{"value":"flutter-tools"},' - '"local_time":{"value":"2023-xx-31 14:32:14.592898"}}}'; // PURPOSEFULLY MALFORMED + '"local_time":{"value":"2023-xx-31 14:32:14.592898 -0500"}}}'; // PURPOSEFULLY MALFORMED logFile.writeAsStringSync(malformedLog); final LogFileStats? query = analytics.logFileStats(); @@ -801,7 +880,8 @@ $initialToolName=${ConfigHandler.dateStamp},$toolsMessageVersion 'The query should be null because the `local_time` value is malformed'); }); - test('Check that the constant kPackageVersion matches pubspec version', () { + test('Version is the same in the change log, pubspec, and constants.dart', + () { // Parse the contents of the pubspec.yaml final String pubspecYamlString = io.File('pubspec.yaml').readAsStringSync(); @@ -814,26 +894,39 @@ $initialToolName=${ConfigHandler.dateStamp},$toolsMessageVersion 'constants.dart need to match\n' 'Pubspec: $version && constants.dart: $kPackageVersion\n\n' 'Make sure both are the same'); + + // Parse the contents of the change log file + final String changeLogFirstLineString = + io.File('CHANGELOG.md').readAsLinesSync().first; + expect(changeLogFirstLineString.substring(3), kPackageVersion, + reason: 'The CHANGELOG.md file needs the first line to ' + 'be the same version as the pubspec and constants.dart'); }); test('Null values for flutter parameters is reflected properly in log file', () { - final Analytics secondAnalytics = Analytics.test( - tool: secondTool, - homeDirectory: home, - measurementId: 'measurementId', - apiSecret: 'apiSecret', - // flutterChannel: flutterChannel, THIS NEEDS TO REMAIN REMOVED - // toolsMessageVersion: toolsMessageVersion, THIS NEEDS TO REMAIN REMOVED - toolsMessage: toolsMessage, - flutterVersion: 'Flutter 3.6.0-7.0.pre.47', - dartVersion: 'Dart 2.19.0', - fs: fs, - platform: platform, - ); + // Use a for loop two initialize the second analytics instance + // twice to account for no events being sent on the first instance + // run for a given tool + Analytics? secondAnalytics; + for (int i = 0; i < 2; i++) { + secondAnalytics = Analytics.test( + tool: secondTool, + homeDirectory: home, + measurementId: 'measurementId', + apiSecret: 'apiSecret', + // flutterChannel: flutterChannel, THIS NEEDS TO REMAIN REMOVED + toolsMessageVersion: toolsMessageVersion, + toolsMessage: toolsMessage, + flutterVersion: 'Flutter 3.6.0-7.0.pre.47', + dartVersion: 'Dart 2.19.0', + fs: fs, + platform: platform, + ); + } // Send an event and check that the query stats reflects what is expected - secondAnalytics.sendEvent( + secondAnalytics!.sendEvent( eventName: DashEvent.hotReloadTime, eventData: {}); // Query the log file stats to verify that there are two tools