sync: Log repo sync state events as 'data' events.

git_trace2_event_log.py:
+ Added LogDataConfigEvents method to log 'data' events.
  Sync's current_sync_state and previous_sync_state are logged
  as 'data' events in the current log.

  It logs are key/value in the |config| argument. Each key is
  prefixed with |prefix| argument.

  The following are sample events that are logged during repo sync.

   {"event":"data",
   "sid":"repo-20210914T181545Z-P000330c0/repo-20210914T181545Z-P000330c0",
   "thread":"MainThread",
   "time":"2021-09-14T18:16:19.935846Z",
   "key":"previous_sync_state/repo.syncstate.main.synctime",
   "value":"2021-09-14T17:27:11.573717Z"}

   {"event":"data",
   "sid":"repo-20210914T181545Z-P000330c0/repo-20210914T181545Z-P000330c0",
   "thread":"MainThread",
   "time":"2021-09-14T18:16:19.955546Z",
   "key":"current_sync_state/repo.syncstate.main.synctime",
   "value":"2021-09-14T18:16:19.935979Z"}

tests/test_git_trace2_event_log.py:
+ Added unit tests

sync.py:
+ Changed logging calls to LogDataConfigEvents.

Tested:
$ ./run_tests

Tested it by running the following command multiple times.
$ repo_dev sync -j 20
  repo sync has finished successfully

  Verified config data is looged in trace2 event logs.

Bug: [google internal] b/199758376
Change-Id: I75fd830e90c1811ec28510538c99a2632b104e85
Reviewed-on: https://gerrit-review.googlesource.com/c/git-repo/+/317823
Reviewed-by: Josh Steadmon <steadmon@google.com>
Reviewed-by: Xin Li <delphij@google.com>
Tested-by: Raman Tenneti <rtenneti@google.com>
This commit is contained in:
Raman Tenneti 2021-09-13 17:40:07 -07:00
parent 1328c35a4d
commit 6448a4f2af
4 changed files with 54 additions and 5 deletions

View File

@ -167,6 +167,22 @@ class EventLog(object):
repo_config = {k: v for k, v in config.items() if k.startswith('repo.')} repo_config = {k: v for k, v in config.items() if k.startswith('repo.')}
self.LogConfigEvents(repo_config, 'def_param') self.LogConfigEvents(repo_config, 'def_param')
def LogDataConfigEvents(self, config, prefix):
"""Append a 'data' event for each config key/value in |config| to the current log.
For each keyX and valueX of the config, "key" field of the event is '|prefix|/keyX'
and the "value" of the "key" field is valueX.
Args:
config: Configuration dictionary.
prefix: Prefix for each key that is logged.
"""
for key, value in config.items():
event = self._CreateEventDict('data')
event['key'] = f'{prefix}/{key}'
event['value'] = value
self._log.append(event)
def ErrorEvent(self, msg, fmt): def ErrorEvent(self, msg, fmt):
"""Append a 'error' event to the current log.""" """Append a 'error' event to the current log."""
error_event = self._CreateEventDict('error') error_event = self._CreateEventDict('error')

View File

@ -1092,12 +1092,12 @@ later is required to fix a server side protocol bug.
sys.exit(1) sys.exit(1)
# Log the previous sync analysis state from the config. # Log the previous sync analysis state from the config.
self.git_event_log.LogConfigEvents(mp.config.GetSyncAnalysisStateData(), self.git_event_log.LogDataConfigEvents(mp.config.GetSyncAnalysisStateData(),
'previous_sync_state') 'previous_sync_state')
# Update and log with the new sync analysis state. # Update and log with the new sync analysis state.
mp.config.UpdateSyncAnalysisState(opt, superproject_logging_data) mp.config.UpdateSyncAnalysisState(opt, superproject_logging_data)
self.git_event_log.LogConfigEvents(mp.config.GetSyncAnalysisStateData(), self.git_event_log.LogDataConfigEvents(mp.config.GetSyncAnalysisStateData(),
'current_sync_state') 'current_sync_state')
if not opt.quiet: if not opt.quiet:

View File

@ -12,7 +12,7 @@
intm = 10m intm = 10m
intg = 10g intg = 10g
[repo "syncstate.main"] [repo "syncstate.main"]
synctime = 2021-08-13T18:37:43.928600Z synctime = 2021-09-14T17:23:43.537338Z
version = 1 version = 1
[repo "syncstate.sys"] [repo "syncstate.sys"]
argv = ['/usr/bin/pytest-3'] argv = ['/usr/bin/pytest-3']

View File

@ -234,6 +234,39 @@ class EventLogTestCase(unittest.TestCase):
self.assertEqual(len(self._log_data), 1) self.assertEqual(len(self._log_data), 1)
self.verifyCommonKeys(self._log_data[0], expected_event_name='version') self.verifyCommonKeys(self._log_data[0], expected_event_name='version')
def test_data_event_config(self):
"""Test 'data' event data outputs all config keys.
Expected event log:
<version event>
<data event>
<data event>
"""
config = {
'git.foo': 'bar',
'repo.partialclone': 'false',
'repo.syncstate.superproject.hassuperprojecttag': 'true',
}
prefix_value = 'prefix'
self._event_log_module.LogDataConfigEvents(config, prefix_value)
with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir:
log_path = self._event_log_module.Write(path=tempdir)
self._log_data = self.readLog(log_path)
self.assertEqual(len(self._log_data), 4)
data_events = self._log_data[1:]
self.verifyCommonKeys(self._log_data[0], expected_event_name='version')
for event in data_events:
self.verifyCommonKeys(event, expected_event_name='data')
# Check for 'data' event specific fields.
self.assertIn('key', event)
self.assertIn('value', event)
key = event['key'].removeprefix(f'{prefix_value}/')
value = event['value']
self.assertTrue(key in config and value == config[key])
def test_error_event(self): def test_error_event(self):
"""Test and validate 'error' event data is valid. """Test and validate 'error' event data is valid.