Files
doormile_milderapp/test/duty_heartbeat_gate_test.dart
2026-08-28 18:16:28 +05:30

354 lines
13 KiB
Dart

import 'dart:convert';
import 'package:flutter_test/flutter_test.dart';
import 'package:http/http.dart' as http;
import 'package:http/testing.dart';
import 'package:shared_preferences/shared_preferences.dart';
import 'package:miler/data/device_telemetry.dart';
import 'package:miler/data/miler_api.dart';
import 'package:miler/providers/Riderlog/riderlog_provider.dart';
/// ─────────────────────────────────────────────────────────────────────────
/// THE TELEMETRY NEVER LEFT THE PHONE
///
/// ── What the dispatcher saw ──
///
/// Battery, Charging, Connection, GPS and Location Service, all blank, on
/// riders whose handsets were measuring every one of them correctly.
///
/// ── Where it actually stopped ──
///
/// Not in [DeviceTelemetry] — `device_telemetry_test.dart` pins that the
/// reading and the payload are right. Not in the callers, which all spread
/// `toPayload()` into the heartbeat. It stopped one layer further down, at a
/// gate in `riderlog_provider.dart`:
///
/// ```
/// if ((prefs.getInt('dutylogid') ?? 0) <= 0) return _startDuty(data);
/// return _heartbeat(data);
/// ```
///
/// `_heartbeat` is the **only** caller of `POST /miler/logs`, and also the only
/// caller of `PUT /miler/location`. Both were unreachable whenever `dutylogid`
/// was zero — and it stayed zero in two ordinary cases, permanently, with
/// nothing anywhere reporting an error:
///
/// • `duty/start` returning a body that does not name the id under that exact
/// key. The zero was then *stored*, so every later tick re-entered
/// `_startDuty`.
/// • `duty/start` answering 400 because the server already had the rider on
/// duty. The reconciliation through `duty/current` recovered the duty state
/// and wrote the id to `logid`/`logId` — never to `dutylogid`.
///
/// These tests drive the provider against a recording client, so what they
/// assert is what the phone would actually put on the wire.
/// ─────────────────────────────────────────────────────────────────────────
void main() {
late List<http.Request> sent;
/// The heartbeat payload a caller builds — the real shape, from
/// `RiderLogController.createLoginNowV2` and the foreground service, both of
/// which spread `DeviceTelemetry.toPayload()` into it.
Map<String, dynamic> payload({int onduty = 1}) => {
'userid': 90001,
'latitude': '12.9716',
'longitude': '77.5946',
'speed': '0',
'heading': '0',
'accuracy': '8.5',
'status': 'active',
'onduty': onduty,
...const DeviceTelemetry(
battery: 72,
isCharging: false,
connection: 'wifi',
locationService: 'enabled',
).toPayload(),
'is_background': false,
};
/// Answers every route with a success envelope. [dutyStartBody] is what
/// `POST /miler/duty/start` returns, which is the variable the bug turned on.
void stub({
Map<String, dynamic> dutyStartBody = const {},
int dutyStartStatus = 200,
Map<String, dynamic> dutyCurrentBody = const {'onduty': true},
}) {
sent = <http.Request>[];
MilerApi.client = MockClient((req) async {
sent.add(req);
final path = req.url.path;
Map<String, dynamic> body = const {};
int status = 200;
if (path.endsWith('/duty/start')) {
body = dutyStartBody;
status = dutyStartStatus;
} else if (path.endsWith('/duty/current')) {
body = dutyCurrentBody;
}
return http.Response(
jsonEncode({'success': status < 400, 'data': body}),
status,
headers: const {'content-type': 'application/json'},
);
});
}
List<http.Request> to(String suffix) =>
sent.where((r) => r.url.path.endsWith(suffix)).toList();
Map<String, dynamic> bodyOf(http.Request r) =>
jsonDecode(r.body) as Map<String, dynamic>;
/// `POST /miler/logs` is deliberately fire-and-forget inside `_heartbeat` — a
/// telemetry failure must never read as a location failure, because the
/// caller treats the latter as duty state going wrong. So the request is in
/// flight, not finished, when the provider returns.
Future<void> settle() => pumpEventQueue();
setUp(() {
SharedPreferences.setMockInitialValues({});
stub();
});
tearDown(() => MilerApi.client = http.Client());
group('the telemetry reaches POST /miler/logs', () {
test(
'every field the console draws is on the wire, under its own name',
() async {
// Duty already established, so this is an ordinary heartbeat tick.
SharedPreferences.setMockInitialValues({'dutylogid': 4242});
await CreateRiderLogProvider().createRiderLog(payload());
await settle();
final logs = to('/miler/logs');
expect(logs, hasLength(1), reason: 'the heartbeat must post one log');
final body = bodyOf(logs.single);
// The names are the wire's. A rename is a console column that goes blank
// with nothing else failing.
expect(body['battery'], '72');
expect(body['is_charging'], false);
expect(body['connection'], 'wifi');
expect(body['location_service'], 'enabled');
expect(body['accuracy'], '8.5');
expect(body['is_background'], false);
expect(body['latitude'], '12.9716');
expect(body['longitude'], '77.5946');
},
);
test('and the location write still happens on the same tick', () async {
// `PUT /miler/location` is the Redis geo-index dispatch searches. It
// shares `_heartbeat` with the telemetry, so it was silenced by the same
// gate — and it must not be lost while fixing the other half.
SharedPreferences.setMockInitialValues({'dutylogid': 4242});
await CreateRiderLogProvider().createRiderLog(payload());
await settle();
expect(to('/miler/location'), hasLength(1));
expect(to('/miler/location').single.method, 'PUT');
});
test(
'REGRESSION · the log post completes before the heartbeat returns',
() async {
// ── Why this matters more than it looks ──
//
// `POST /miler/logs` was `unawaited(...)`, to keep a telemetry failure
// from reading as a location failure. On Android the heartbeat runs
// inside `flutter_foreground_task`'s own Flutter engine, spun up per
// tick — and when the callback returns, that engine can be suspended
// before an in-flight future finishes. So the awaited
// `PUT /miler/location` landed every tick and this post was killed
// mid-flight.
//
// The backend saw it before we did: a rider with a live position in
// Redis and no telemetry row behind it, while the app logged a
// successful heartbeat.
//
// Asserting *without* pumping the event queue is the whole point: if
// the post ever goes back to being fire-and-forget, the request has not
// been made yet at this line and this fails.
SharedPreferences.setMockInitialValues({'dutylogid': 4242});
await CreateRiderLogProvider().createRiderLog(payload());
expect(
to('/miler/logs'),
hasLength(1),
reason: 'the telemetry post must finish before the tick returns',
);
},
);
test('no fix means no post, which is the contract, not a bug', () async {
SharedPreferences.setMockInitialValues({'dutylogid': 4242});
await CreateRiderLogProvider().createRiderLog({
...payload(),
'latitude': '',
'longitude': '',
});
await settle();
expect(to('/miler/logs'), isEmpty);
expect(to('/miler/location'), isEmpty);
});
});
group('the gate that swallowed it', () {
test(
'REGRESSION · duty/start that does not name the id still heartbeats',
() async {
// The exact defect: an empty `data` body. The old code parsed 0, STORED
// 0, and every later tick re-entered `_startDuty` — so `/miler/logs`
// was never posted, on the rider's first shift, forever.
stub(dutyStartBody: const {});
await CreateRiderLogProvider().createRiderLog(payload());
await settle();
expect(to('/miler/duty/start'), hasLength(1));
expect(
to('/miler/logs'),
hasLength(1),
reason: 'starting duty must not cost the rider the tick that did it',
);
// And the next tick is a plain heartbeat, not another start attempt.
final before = to('/miler/duty/start').length;
await CreateRiderLogProvider().createRiderLog(payload());
await settle();
expect(to('/miler/duty/start'), hasLength(before));
expect(to('/miler/logs'), hasLength(2));
},
);
test(
'REGRESSION · "already on duty" reconciles AND opens the gate',
() async {
// `duty/start` 400s because the server already has him on duty — after
// a reinstall, cleared storage, or an `endDuty` that never landed. The
// reconciliation through `duty/current` used to write the id to
// `logid`/`logId` and not to `dutylogid`, so the gate stayed shut and
// the next tick came straight back here. Permanently.
stub(
dutyStartStatus: 400,
dutyCurrentBody: const {'onduty': true, 'dutylogid': 77},
);
await CreateRiderLogProvider().createRiderLog(payload());
await settle();
expect(to('/miler/duty/current'), hasLength(1));
expect(
to('/miler/logs'),
hasLength(1),
reason: 'a reconciled rider must report, not loop on duty/start',
);
final prefs = await SharedPreferences.getInstance();
expect(prefs.getInt('dutylogid'), 77);
// The loop is broken: no second start attempt.
await CreateRiderLogProvider().createRiderLog(payload());
await settle();
expect(to('/miler/duty/start'), hasLength(1));
expect(to('/miler/logs'), hasLength(2));
},
);
test('the id is found however the response spells it', () async {
// One key on one level was the whole lookup. These are shapes this
// contract has worn; a miss is no longer fatal, but the legacy `logid`
// readers still want the number.
for (final key in ['dutylogid', 'dutyLogId', 'logid', 'id']) {
SharedPreferences.setMockInitialValues({});
stub(dutyStartBody: {key: 501});
await CreateRiderLogProvider().createRiderLog(payload());
await settle();
final prefs = await SharedPreferences.getInstance();
expect(
prefs.getInt('dutylogid'),
501,
reason: 'the id was sent as `$key`',
);
}
});
test('an install from before the flag keeps reporting', () async {
// A rider mid-shift when he takes the update. He must not have to go off
// duty and on again to start reporting, and he must not re-start duty.
SharedPreferences.setMockInitialValues({'dutylogid': 909});
await CreateRiderLogProvider().createRiderLog(payload());
await settle();
expect(to('/miler/duty/start'), isEmpty);
expect(to('/miler/logs'), hasLength(1));
});
});
group('the update path is gated the same way', () {
test(
'an on-duty update establishes duty and beats on the same tick',
() async {
stub(dutyStartBody: const {});
await UpdateRiderLogProvider().updateRiderLog(payload());
await settle();
expect(to('/miler/duty/start'), hasLength(1));
expect(to('/miler/logs'), hasLength(1));
},
);
test('going off duty ends it and stops the heartbeat', () async {
SharedPreferences.setMockInitialValues({'dutylogid': 4242});
await UpdateRiderLogProvider().updateRiderLog({
...payload(onduty: 0),
'onduty': 0,
});
await settle();
expect(to('/miler/duty/end'), hasLength(1));
expect(
to('/miler/logs'),
isEmpty,
reason: 'an off-duty payload is not a heartbeat',
);
final prefs = await SharedPreferences.getInstance();
expect(prefs.getInt('dutylogid'), 0);
// And the next tick starts duty again rather than beating into a shift
// that has ended.
await CreateRiderLogProvider().createRiderLog(payload());
await settle();
expect(to('/miler/duty/start'), hasLength(1));
});
test('duty/current reporting off duty closes the gate', () async {
// The server is the authority. If it says the rider is off, the app must
// not keep beating on a stale local flag.
SharedPreferences.setMockInitialValues({'dutylogid': 4242});
stub(dutyCurrentBody: const {'onduty': false});
await GetRiderLogProvider().getRiderLog();
await settle();
final prefs = await SharedPreferences.getInstance();
expect(prefs.getInt('onduty'), 0);
expect(prefs.getInt('dutylogid'), 0);
});
});
}