• Home
  • Features
  • Pricing
  • Docs
  • Announcements
  • Sign In

realm / realm-core / 2458

01 Jul 2024 04:59PM UTC coverage: 91.147% (+0.1%) from 91.001%
2458

push

Evergreen

web-flow
Merge pull request #7796 from realm/tg/upload-completion

RCORE-2160 Make upload completion reporting multiprocess-compatible

103762 of 182414 branches covered (56.88%)

136 of 139 new or added lines in 8 files covered. (97.84%)

52 existing lines in 11 files now uncovered.

216754 of 237806 relevant lines covered (91.15%)

5777851.99 hits per line

Source File
Press 'n' to go to next uncovered line, 'b' for previous

87.67
/src/realm/sync/noinst/client_impl_base.cpp
1
#include <realm/sync/noinst/client_impl_base.hpp>
2

3
#include <realm/impl/simulated_failure.hpp>
4
#include <realm/sync/changeset_parser.hpp>
5
#include <realm/sync/impl/clock.hpp>
6
#include <realm/sync/network/http.hpp>
7
#include <realm/sync/network/websocket.hpp>
8
#include <realm/sync/noinst/client_history_impl.hpp>
9
#include <realm/sync/noinst/compact_changesets.hpp>
10
#include <realm/sync/noinst/client_reset_operation.hpp>
11
#include <realm/sync/noinst/sync_schema_migration.hpp>
12
#include <realm/sync/protocol.hpp>
13
#include <realm/util/assert.hpp>
14
#include <realm/util/basic_system_errors.hpp>
15
#include <realm/util/memory_stream.hpp>
16
#include <realm/util/platform_info.hpp>
17
#include <realm/util/random.hpp>
18
#include <realm/util/safe_int_ops.hpp>
19
#include <realm/util/scope_exit.hpp>
20
#include <realm/util/to_string.hpp>
21
#include <realm/util/uri.hpp>
22
#include <realm/version.hpp>
23

24
#include <realm/sync/network/websocket.hpp> // Only for websocket::Error TODO remove
25

26
#include <system_error>
27
#include <sstream>
28

29
// NOTE: The protocol specification is in `/doc/protocol.md`
30

31
using namespace realm;
32
using namespace _impl;
33
using namespace realm::util;
34
using namespace realm::sync;
35
using namespace realm::sync::websocket;
36

37
// clang-format off
38
using Connection      = ClientImpl::Connection;
39
using Session         = ClientImpl::Session;
40
using UploadChangeset = ClientHistory::UploadChangeset;
41

42
// These are a work-around for a bug in MSVC. It cannot find in-class types
43
// mentioned in signature of out-of-line member function definitions.
44
using ConnectionTerminationReason = ClientImpl::ConnectionTerminationReason;
45
using OutputBuffer                = ClientImpl::OutputBuffer;
46
using ReceivedChangesets          = ClientProtocol::ReceivedChangesets;
47
// clang-format on
48

49
void ClientImpl::ReconnectInfo::reset() noexcept
50
{
1,922✔
51
    m_backoff_state.reset();
1,922✔
52
    scheduled_reset = false;
1,922✔
53
}
1,922✔
54

55

56
void ClientImpl::ReconnectInfo::update(ConnectionTerminationReason new_reason,
57
                                       std::optional<ResumptionDelayInfo> new_delay_info)
58
{
3,766✔
59
    m_backoff_state.update(new_reason, new_delay_info);
3,766✔
60
}
3,766✔
61

62

63
std::chrono::milliseconds ClientImpl::ReconnectInfo::delay_interval()
64
{
6,022✔
65
    if (scheduled_reset) {
6,022✔
66
        reset();
8✔
67
    }
8✔
68

69
    if (!m_backoff_state.triggering_error) {
6,022✔
70
        return std::chrono::milliseconds::zero();
4,612✔
71
    }
4,612✔
72

73
    switch (*m_backoff_state.triggering_error) {
1,410✔
74
        case ConnectionTerminationReason::closed_voluntarily:
80✔
75
            return std::chrono::milliseconds::zero();
80✔
76
        case ConnectionTerminationReason::server_said_do_not_reconnect:
18✔
77
            return std::chrono::milliseconds::max();
18✔
78
        default:
1,312✔
79
            if (m_reconnect_mode == ReconnectMode::testing) {
1,312✔
80
                return std::chrono::milliseconds::max();
982✔
81
            }
982✔
82

83
            REALM_ASSERT(m_reconnect_mode == ReconnectMode::normal);
330✔
84
            return m_backoff_state.delay_interval();
330✔
85
    }
1,410✔
86
}
1,410✔
87

88

89
bool ClientImpl::decompose_server_url(const std::string& url, ProtocolEnvelope& protocol, std::string& address,
90
                                      port_type& port, std::string& path) const
91
{
4,038✔
92
    util::Uri uri(url); // Throws
4,038✔
93
    uri.canonicalize(); // Throws
4,038✔
94
    std::string userinfo, address_2, port_2;
4,038✔
95
    bool realm_scheme = (uri.get_scheme() == "realm:" || uri.get_scheme() == "realms:");
4,038✔
96
    bool ws_scheme = (uri.get_scheme() == "ws:" || uri.get_scheme() == "wss:");
4,038✔
97
    bool good = ((realm_scheme || ws_scheme) && uri.get_auth(userinfo, address_2, port_2) && userinfo.empty() &&
4,038✔
98
                 !address_2.empty() && uri.get_query().empty() && uri.get_frag().empty()); // Throws
4,038✔
99
    if (REALM_UNLIKELY(!good))
4,038✔
100
        return false;
×
101
    ProtocolEnvelope protocol_2;
4,038✔
102
    port_type port_3;
4,038✔
103
    if (realm_scheme) {
4,038✔
104
        if (uri.get_scheme() == "realm:") {
×
105
            protocol_2 = ProtocolEnvelope::realm;
×
106
            port_3 = (m_enable_default_port_hack ? 80 : 7800);
×
107
        }
×
108
        else {
×
109
            protocol_2 = ProtocolEnvelope::realms;
×
110
            port_3 = (m_enable_default_port_hack ? 443 : 7801);
×
111
        }
×
112
    }
×
113
    else {
4,038✔
114
        REALM_ASSERT(ws_scheme);
4,038✔
115
        if (uri.get_scheme() == "ws:") {
4,038✔
116
            protocol_2 = ProtocolEnvelope::ws;
3,958✔
117
            port_3 = 80;
3,958✔
118
        }
3,958✔
119
        else {
80✔
120
            protocol_2 = ProtocolEnvelope::wss;
80✔
121
            port_3 = 443;
80✔
122
        }
80✔
123
    }
4,038✔
124
    if (!port_2.empty()) {
4,038✔
125
        std::istringstream in(port_2);    // Throws
3,934✔
126
        in.imbue(std::locale::classic()); // Throws
3,934✔
127
        in >> port_3;
3,934✔
128
        if (REALM_UNLIKELY(!in || !in.eof() || port_3 < 1))
3,934✔
129
            return false;
×
130
    }
3,934✔
131
    std::string path_2 = uri.get_path(); // Throws (copy)
4,038✔
132

133
    protocol = protocol_2;
4,038✔
134
    address = std::move(address_2);
4,038✔
135
    port = port_3;
4,038✔
136
    path = std::move(path_2);
4,038✔
137
    return true;
4,038✔
138
}
4,038✔
139

140
ClientImpl::ClientImpl(ClientConfig config)
141
    : logger_ptr{std::make_shared<util::CategoryLogger>(util::LogCategory::session, std::move(config.logger))}
4,898✔
142
    , logger{*logger_ptr}
4,898✔
143
    , m_reconnect_mode{config.reconnect_mode}
4,898✔
144
    , m_connect_timeout{config.connect_timeout}
4,898✔
145
    , m_connection_linger_time{config.one_connection_per_session ? 0 : config.connection_linger_time}
4,898✔
146
    , m_ping_keepalive_period{config.ping_keepalive_period}
4,898✔
147
    , m_pong_keepalive_timeout{config.pong_keepalive_timeout}
4,898✔
148
    , m_fast_reconnect_limit{config.fast_reconnect_limit}
4,898✔
149
    , m_reconnect_backoff_info{config.reconnect_backoff_info}
4,898✔
150
    , m_disable_upload_activation_delay{config.disable_upload_activation_delay}
4,898✔
151
    , m_dry_run{config.dry_run}
4,898✔
152
    , m_enable_default_port_hack{config.enable_default_port_hack}
4,898✔
153
    , m_disable_upload_compaction{config.disable_upload_compaction}
4,898✔
154
    , m_fix_up_object_ids{config.fix_up_object_ids}
4,898✔
155
    , m_roundtrip_time_handler{std::move(config.roundtrip_time_handler)}
4,898✔
156
    , m_socket_provider{std::move(config.socket_provider)}
4,898✔
157
    , m_client_protocol{} // Throws
4,898✔
158
    , m_one_connection_per_session{config.one_connection_per_session}
4,898✔
159
    , m_random{}
4,898✔
160
{
9,934✔
161
    // FIXME: Would be better if seeding was up to the application.
162
    util::seed_prng_nondeterministically(m_random); // Throws
9,934✔
163

164
    logger.info("Realm sync client (%1)", REALM_VER_CHUNK); // Throws
9,934✔
165
    logger.debug("Supported protocol versions: %1-%2", get_oldest_supported_protocol_version(),
9,934✔
166
                 get_current_protocol_version()); // Throws
9,934✔
167
    logger.info("Platform: %1", util::get_platform_info());
9,934✔
168
    const char* build_mode;
9,934✔
169
#if REALM_DEBUG
9,934✔
170
    build_mode = "Debug";
9,934✔
171
#else
172
    build_mode = "Release";
173
#endif
174
    logger.debug("Build mode: %1", build_mode);
9,934✔
175
    logger.debug("Config param: one_connection_per_session = %1",
9,934✔
176
                 config.one_connection_per_session); // Throws
9,934✔
177
    logger.debug("Config param: connect_timeout = %1 ms",
9,934✔
178
                 config.connect_timeout); // Throws
9,934✔
179
    logger.debug("Config param: connection_linger_time = %1 ms",
9,934✔
180
                 config.connection_linger_time); // Throws
9,934✔
181
    logger.debug("Config param: ping_keepalive_period = %1 ms",
9,934✔
182
                 config.ping_keepalive_period); // Throws
9,934✔
183
    logger.debug("Config param: pong_keepalive_timeout = %1 ms",
9,934✔
184
                 config.pong_keepalive_timeout); // Throws
9,934✔
185
    logger.debug("Config param: fast_reconnect_limit = %1 ms",
9,934✔
186
                 config.fast_reconnect_limit); // Throws
9,934✔
187
    logger.debug("Config param: disable_upload_compaction = %1",
9,934✔
188
                 config.disable_upload_compaction); // Throws
9,934✔
189
    logger.debug("Config param: disable_sync_to_disk = %1",
9,934✔
190
                 config.disable_sync_to_disk); // Throws
9,934✔
191
    logger.debug(
9,934✔
192
        "Config param: reconnect backoff info: max_delay: %1 ms, initial_delay: %2 ms, multiplier: %3, jitter: 1/%4",
9,934✔
193
        m_reconnect_backoff_info.max_resumption_delay_interval.count(),
9,934✔
194
        m_reconnect_backoff_info.resumption_delay_interval.count(),
9,934✔
195
        m_reconnect_backoff_info.resumption_delay_backoff_multiplier, m_reconnect_backoff_info.delay_jitter_divisor);
9,934✔
196

197
    if (config.reconnect_mode != ReconnectMode::normal) {
9,934✔
198
        logger.warn("Testing/debugging feature 'nonnormal reconnect mode' enabled - "
776✔
199
                    "never do this in production!");
776✔
200
    }
776✔
201

202
    if (config.dry_run) {
9,934✔
203
        logger.warn("Testing/debugging feature 'dry run' enabled - "
×
204
                    "never do this in production!");
×
205
    }
×
206

207
    REALM_ASSERT_EX(m_socket_provider, "Must provide socket provider in sync Client config");
9,934✔
208

209
    if (m_one_connection_per_session) {
9,934✔
210
        logger.warn("Testing/debugging feature 'one connection per session' enabled - "
4✔
211
                    "never do this in production");
4✔
212
    }
4✔
213

214
    if (config.disable_upload_activation_delay) {
9,934✔
215
        logger.warn("Testing/debugging feature 'disable_upload_activation_delay' enabled - "
×
216
                    "never do this in production");
×
217
    }
×
218

219
    if (config.disable_sync_to_disk) {
9,934✔
220
        logger.warn("Testing/debugging feature 'disable_sync_to_disk' enabled - "
×
221
                    "never do this in production");
×
222
    }
×
223

224
    m_actualize_and_finalize = create_trigger([this](Status status) {
14,338✔
225
        if (status == ErrorCodes::OperationAborted)
14,338✔
226
            return;
×
227
        else if (!status.is_ok())
14,338✔
228
            throw Exception(status);
×
229
        actualize_and_finalize_session_wrappers(); // Throws
14,338✔
230
    });
14,338✔
231
}
9,934✔
232

233
void ClientImpl::incr_outstanding_posts()
234
{
198,300✔
235
    util::CheckedLockGuard lock(m_drain_mutex);
198,300✔
236
    ++m_outstanding_posts;
198,300✔
237
    m_drained = false;
198,300✔
238
}
198,300✔
239

240
void ClientImpl::decr_outstanding_posts()
241
{
198,262✔
242
    util::CheckedLockGuard lock(m_drain_mutex);
198,262✔
243
    REALM_ASSERT(m_outstanding_posts);
198,262✔
244
    if (--m_outstanding_posts <= 0) {
198,262✔
245
        // Notify must happen with lock held or another thread could destroy
246
        // ClientImpl between when we release the lock and when we call notify
247
        m_drain_cv.notify_all();
18,086✔
248
    }
18,086✔
249
}
198,262✔
250

251
void ClientImpl::post(SyncSocketProvider::FunctionHandler&& handler)
252
{
41,224✔
253
    REALM_ASSERT(m_socket_provider);
41,224✔
254
    incr_outstanding_posts();
41,224✔
255
    m_socket_provider->post([handler = std::move(handler), this](Status status) {
41,224✔
256
        auto decr_guard = util::make_scope_exit([&]() noexcept {
41,198✔
257
            decr_outstanding_posts();
41,198✔
258
        });
41,198✔
259
        handler(status);
41,198✔
260
    });
41,198✔
261
}
41,224✔
262

263
void ClientImpl::post(util::UniqueFunction<void()>&& handler)
264
{
139,980✔
265
    REALM_ASSERT(m_socket_provider);
139,980✔
266
    incr_outstanding_posts();
139,980✔
267
    m_socket_provider->post([handler = std::move(handler), this](Status status) {
139,982✔
268
        auto decr_guard = util::make_scope_exit([&]() noexcept {
139,982✔
269
            decr_outstanding_posts();
139,980✔
270
        });
139,980✔
271
        if (status == ErrorCodes::OperationAborted)
139,980✔
272
            return;
×
273
        if (!status.is_ok())
139,980✔
274
            throw Exception(status);
×
275
        handler();
139,980✔
276
    });
139,980✔
277
}
139,980✔
278

279

280
void ClientImpl::drain_connections()
281
{
9,922✔
282
    logger.debug("Draining connections during sync client shutdown");
9,922✔
283
    for (auto& server_slot_pair : m_server_slots) {
9,922✔
284
        auto& server_slot = server_slot_pair.second;
2,672✔
285

286
        if (server_slot.connection) {
2,672✔
287
            auto& conn = server_slot.connection;
2,460✔
288
            conn->force_close();
2,460✔
289
        }
2,460✔
290
        else {
212✔
291
            for (auto& conn_pair : server_slot.alt_connections) {
212✔
292
                conn_pair.second->force_close();
×
293
            }
×
294
        }
212✔
295
    }
2,672✔
296
}
9,922✔
297

298

299
SyncSocketProvider::SyncTimer ClientImpl::create_timer(std::chrono::milliseconds delay,
300
                                                       SyncSocketProvider::FunctionHandler&& handler)
301
{
17,104✔
302
    REALM_ASSERT(m_socket_provider);
17,104✔
303
    incr_outstanding_posts();
17,104✔
304
    return m_socket_provider->create_timer(delay, [handler = std::move(handler), this](Status status) {
17,104✔
305
        auto decr_guard = util::make_scope_exit([&]() noexcept {
17,088✔
306
            decr_outstanding_posts();
17,082✔
307
        });
17,082✔
308
        handler(status);
17,088✔
309
    });
17,088✔
310
}
17,104✔
311

312

313
ClientImpl::SyncTrigger ClientImpl::create_trigger(SyncSocketProvider::FunctionHandler&& handler)
314
{
12,726✔
315
    REALM_ASSERT(m_socket_provider);
12,726✔
316
    return std::make_unique<Trigger<ClientImpl>>(this, std::move(handler));
12,726✔
317
}
12,726✔
318

319
Connection::~Connection()
320
{
2,780✔
321
    if (m_websocket_sentinel) {
2,780✔
322
        m_websocket_sentinel->destroyed = true;
×
323
        m_websocket_sentinel.reset();
×
324
    }
×
325
}
2,780✔
326

327
void Connection::activate()
328
{
2,786✔
329
    REALM_ASSERT(m_on_idle);
2,786✔
330
    m_activated = true;
2,786✔
331
    if (m_num_active_sessions == 0)
2,786✔
332
        m_on_idle->trigger();
×
333
    // We cannot in general connect immediately, because a prior failure to
334
    // connect may require a delay before reconnecting (see `m_reconnect_info`).
335
    initiate_reconnect_wait(); // Throws
2,786✔
336
}
2,786✔
337

338

339
void Connection::activate_session(std::unique_ptr<Session> sess)
340
{
10,050✔
341
    REALM_ASSERT(sess);
10,050✔
342
    REALM_ASSERT(&sess->m_conn == this);
10,050✔
343
    REALM_ASSERT(!m_force_closed);
10,050✔
344
    Session& sess_2 = *sess;
10,050✔
345
    session_ident_type ident = sess->m_ident;
10,050✔
346
    auto p = m_sessions.emplace(ident, std::move(sess)); // Throws
10,050✔
347
    bool was_inserted = p.second;
10,050✔
348
    REALM_ASSERT(was_inserted);
10,050✔
349
    // Save the session ident to the historical list of session idents
350
    m_session_history.insert(ident);
10,050✔
351
    sess_2.activate(); // Throws
10,050✔
352
    if (m_state == ConnectionState::connected) {
10,050✔
353
        bool fast_reconnect = false;
6,940✔
354
        sess_2.connection_established(fast_reconnect); // Throws
6,940✔
355
    }
6,940✔
356
    ++m_num_active_sessions;
10,050✔
357
}
10,050✔
358

359

360
void Connection::initiate_session_deactivation(Session* sess)
361
{
10,040✔
362
    REALM_ASSERT(sess);
10,040✔
363
    REALM_ASSERT(&sess->m_conn == this);
10,040✔
364
    REALM_ASSERT(m_num_active_sessions);
10,040✔
365
    // Since the client may be waiting for m_num_active_sessions to reach 0
366
    // in stop_and_wait() (on a separate thread), deactivate Session before
367
    // decrementing the num active sessions value.
368
    sess->initiate_deactivation(); // Throws
10,040✔
369
    if (sess->m_state == Session::Deactivated) {
10,040✔
370
        finish_session_deactivation(sess);
896✔
371
    }
896✔
372
    if (REALM_UNLIKELY(--m_num_active_sessions == 0)) {
10,040✔
373
        if (m_activated && m_state == ConnectionState::disconnected)
4,338✔
374
            m_on_idle->trigger();
360✔
375
    }
4,338✔
376
}
10,040✔
377

378

379
void Connection::cancel_reconnect_delay()
380
{
2,136✔
381
    REALM_ASSERT(m_activated);
2,136✔
382

383
    if (m_reconnect_delay_in_progress) {
2,136✔
384
        if (m_nonzero_reconnect_delay)
1,910✔
385
            logger.detail("Canceling reconnect delay"); // Throws
954✔
386

387
        // Cancel the in-progress wait operation by destroying the timer
388
        // object. Destruction is needed in this case, because a new wait
389
        // operation might have to be initiated before the previous one
390
        // completes (its completion handler starts to execute), so the new wait
391
        // operation must be done on a new timer object.
392
        m_reconnect_disconnect_timer.reset();
1,910✔
393
        m_reconnect_delay_in_progress = false;
1,910✔
394
        m_reconnect_info.reset();
1,910✔
395
        initiate_reconnect_wait(); // Throws
1,910✔
396
        return;
1,910✔
397
    }
1,910✔
398

399
    // If we are not disconnected, then we need to make sure the next time we get disconnected
400
    // that we are allowed to re-connect as quickly as possible.
401
    //
402
    // Setting m_reconnect_info.scheduled_reset will cause initiate_reconnect_wait to reset the
403
    // backoff/delay state before calculating the next delay, unless a PONG message is received
404
    // for the urgent PING message we send below.
405
    //
406
    // If we get a PONG message for the urgent PING message sent below, then the connection is
407
    // healthy and we can calculate the next delay normally.
408
    if (m_state != ConnectionState::disconnected) {
226✔
409
        m_reconnect_info.scheduled_reset = true;
226✔
410
        m_ping_after_scheduled_reset_of_reconnect_info = false;
226✔
411

412
        schedule_urgent_ping(); // Throws
226✔
413
        return;
226✔
414
    }
226✔
415
    // Nothing to do in this case. The next reconnect attemp will be made as
416
    // soon as there are any sessions that are both active and unsuspended.
417
}
226✔
418

419
void Connection::finish_session_deactivation(Session* sess)
420
{
7,720✔
421
    REALM_ASSERT(sess->m_state == Session::Deactivated);
7,720✔
422
    auto ident = sess->m_ident;
7,720✔
423
    m_sessions.erase(ident);
7,720✔
424
    m_session_history.erase(ident);
7,720✔
425
}
7,720✔
426

427
void Connection::force_close()
428
{
2,460✔
429
    if (m_force_closed) {
2,460✔
430
        return;
×
431
    }
×
432

433
    m_force_closed = true;
2,460✔
434

435
    if (m_state != ConnectionState::disconnected) {
2,460✔
436
        voluntary_disconnect();
2,428✔
437
    }
2,428✔
438

439
    REALM_ASSERT_EX(m_state == ConnectionState::disconnected, m_state);
2,460✔
440
    if (m_reconnect_delay_in_progress || m_disconnect_delay_in_progress) {
2,460✔
441
        m_reconnect_disconnect_timer.reset();
32✔
442
        m_reconnect_delay_in_progress = false;
32✔
443
        m_disconnect_delay_in_progress = false;
32✔
444
    }
32✔
445

446
    // We must copy any session pointers we want to close to a vector because force_closing
447
    // the session may remove it from m_sessions and invalidate the iterator uses to loop
448
    // through the map. By copying to a separate vector we ensure our iterators remain valid.
449
    std::vector<Session*> to_close;
2,460✔
450
    for (auto& session_pair : m_sessions) {
2,460✔
451
        if (session_pair.second->m_state == Session::State::Active) {
102✔
452
            to_close.push_back(session_pair.second.get());
102✔
453
        }
102✔
454
    }
102✔
455

456
    for (auto& sess : to_close) {
2,460✔
457
        sess->force_close();
102✔
458
    }
102✔
459

460
    logger.debug("Force closed idle connection");
2,460✔
461
}
2,460✔
462

463

464
void Connection::websocket_connected_handler(const std::string& protocol)
465
{
3,560✔
466
    if (!protocol.empty()) {
3,560✔
467
        std::string_view expected_prefix =
3,560✔
468
            is_flx_sync_connection() ? get_flx_websocket_protocol_prefix() : get_pbs_websocket_protocol_prefix();
3,560✔
469
        // FIXME: Use std::string_view::begins_with() in C++20.
470
        auto prefix_matches = [&](std::string_view other) {
3,560✔
471
            return protocol.size() >= other.size() && (protocol.substr(0, other.size()) == other);
3,560✔
472
        };
3,560✔
473
        if (prefix_matches(expected_prefix)) {
3,560✔
474
            util::MemoryInputStream in;
3,560✔
475
            in.set_buffer(protocol.data() + expected_prefix.size(), protocol.data() + protocol.size());
3,560✔
476
            in.imbue(std::locale::classic());
3,560✔
477
            in.unsetf(std::ios_base::skipws);
3,560✔
478
            int value_2 = 0;
3,560✔
479
            in >> value_2;
3,560✔
480
            if (in && in.eof() && value_2 >= 0) {
3,560✔
481
                bool good_version =
3,560✔
482
                    (value_2 >= get_oldest_supported_protocol_version() && value_2 <= get_current_protocol_version());
3,560✔
483
                if (good_version) {
3,560✔
484
                    logger.detail("Negotiated protocol version: %1", value_2);
3,560✔
485
                    // For now, grab the connection ID from the websocket if it supports it. In the future, the server
486
                    // will provide the appservices connection ID via a log message.
487
                    // TODO: Remove once the server starts sending the connection ID
488
                    receive_appservices_request_id(m_websocket->get_appservices_request_id());
3,560✔
489
                    m_negotiated_protocol_version = value_2;
3,560✔
490
                    handle_connection_established(); // Throws
3,560✔
491
                    return;
3,560✔
492
                }
3,560✔
493
            }
3,560✔
494
        }
3,560✔
495
        close_due_to_client_side_error({ErrorCodes::SyncProtocolNegotiationFailed,
×
496
                                        util::format("Bad protocol info from server: '%1'", protocol)},
×
497
                                       IsFatal{true}, ConnectionTerminationReason::bad_headers_in_http_response);
×
498
    }
×
499
    else {
×
500
        close_due_to_client_side_error(
×
501
            {ErrorCodes::SyncProtocolNegotiationFailed, "Missing protocol info from server"}, IsFatal{true},
×
502
            ConnectionTerminationReason::bad_headers_in_http_response);
×
503
    }
×
504
}
3,560✔
505

506

507
bool Connection::websocket_binary_message_received(util::Span<const char> data)
508
{
79,654✔
509
    if (m_force_closed) {
79,654✔
510
        logger.debug("Received binary message after connection was force closed");
×
511
        return false;
×
512
    }
×
513

514
    using sf = SimulatedFailure;
79,654✔
515
    if (sf::check_trigger(sf::sync_client__read_head)) {
79,654✔
516
        close_due_to_client_side_error(
434✔
517
            {ErrorCodes::RuntimeError, "Simulated failure during sync client websocket read"}, IsFatal{false},
434✔
518
            ConnectionTerminationReason::read_or_write_error);
434✔
519
        return bool(m_websocket);
434✔
520
    }
434✔
521

522
    handle_message_received(data);
79,220✔
523
    return bool(m_websocket);
79,220✔
524
}
79,654✔
525

526

527
void Connection::websocket_error_handler()
528
{
712✔
529
    m_websocket_error_received = true;
712✔
530
}
712✔
531

532
bool Connection::websocket_closed_handler(bool was_clean, WebSocketError error_code, std::string_view msg)
533
{
816✔
534
    if (m_force_closed) {
816✔
535
        logger.debug("Received websocket close message after connection was force closed");
×
536
        return false;
×
537
    }
×
538
    logger.info("Closing the websocket with error code=%1, message='%2', was_clean=%3", error_code, msg, was_clean);
816✔
539

540
    switch (error_code) {
816✔
541
        case WebSocketError::websocket_ok:
56✔
542
            break;
56✔
543
        case WebSocketError::websocket_resolve_failed:
4✔
544
            [[fallthrough]];
4✔
545
        case WebSocketError::websocket_connection_failed: {
112✔
546
            SessionErrorInfo error_info(
112✔
547
                {ErrorCodes::SyncConnectFailed, util::format("Failed to connect to sync: %1", msg)}, IsFatal{false});
112✔
548
            // If the connection fails/times out and the server has not been contacted yet, refresh the location
549
            // to make sure the websocket URL is correct
550
            if (!m_server_endpoint.is_verified) {
112✔
551
                error_info.server_requests_action = ProtocolErrorInfo::Action::RefreshLocation;
84✔
552
            }
84✔
553
            involuntary_disconnect(std::move(error_info), ConnectionTerminationReason::connect_operation_failed);
112✔
554
            break;
112✔
555
        }
4✔
556
        case WebSocketError::websocket_read_error:
578✔
557
            [[fallthrough]];
578✔
558
        case WebSocketError::websocket_write_error: {
578✔
559
            close_due_to_transient_error({ErrorCodes::ConnectionClosed, msg},
578✔
560
                                         ConnectionTerminationReason::read_or_write_error);
578✔
561
            break;
578✔
562
        }
578✔
563
        case WebSocketError::websocket_going_away:
✔
564
            [[fallthrough]];
×
565
        case WebSocketError::websocket_protocol_error:
✔
566
            [[fallthrough]];
×
567
        case WebSocketError::websocket_unsupported_data:
✔
568
            [[fallthrough]];
×
569
        case WebSocketError::websocket_invalid_payload_data:
✔
570
            [[fallthrough]];
×
571
        case WebSocketError::websocket_policy_violation:
✔
572
            [[fallthrough]];
×
573
        case WebSocketError::websocket_reserved:
✔
574
            [[fallthrough]];
×
575
        case WebSocketError::websocket_no_status_received:
✔
576
            [[fallthrough]];
×
577
        case WebSocketError::websocket_invalid_extension: {
✔
578
            close_due_to_client_side_error({ErrorCodes::SyncProtocolInvariantFailed, msg}, IsFatal{false},
×
579
                                           ConnectionTerminationReason::websocket_protocol_violation); // Throws
×
580
            break;
×
581
        }
×
582
        case WebSocketError::websocket_message_too_big: {
4✔
583
            auto message = util::format(
4✔
584
                "Sync websocket closed because the server received a message that was too large: %1", msg);
4✔
585
            SessionErrorInfo error_info(Status(ErrorCodes::LimitExceeded, std::move(message)), IsFatal{false});
4✔
586
            error_info.server_requests_action = ProtocolErrorInfo::Action::ClientReset;
4✔
587
            involuntary_disconnect(std::move(error_info),
4✔
588
                                   ConnectionTerminationReason::websocket_protocol_violation); // Throws
4✔
589
            break;
4✔
590
        }
×
591
        case WebSocketError::websocket_tls_handshake_failed: {
10✔
592
            close_due_to_client_side_error(
10✔
593
                Status(ErrorCodes::TlsHandshakeFailed, util::format("TLS handshake failed: %1", msg)), IsFatal{false},
10✔
594
                ConnectionTerminationReason::ssl_certificate_rejected); // Throws
10✔
595
            break;
10✔
596
        }
×
597
        case WebSocketError::websocket_client_too_old:
✔
598
            [[fallthrough]];
×
599
        case WebSocketError::websocket_client_too_new:
✔
600
            [[fallthrough]];
×
601
        case WebSocketError::websocket_protocol_mismatch: {
✔
602
            close_due_to_client_side_error({ErrorCodes::SyncProtocolNegotiationFailed, msg}, IsFatal{true},
×
603
                                           ConnectionTerminationReason::http_response_says_fatal_error); // Throws
×
604
            break;
×
605
        }
×
606
        case WebSocketError::websocket_fatal_error: {
✔
607
            // Error is fatal if the sync_route has already been verified - if the sync_route has not
608
            // been verified, then use a non-fatal error and try to perform a location update.
609
            SessionErrorInfo error_info(
×
610
                {ErrorCodes::SyncConnectFailed, util::format("Failed to connect to sync: %1", msg)},
×
611
                IsFatal{m_server_endpoint.is_verified});
×
612
            ConnectionTerminationReason reason = ConnectionTerminationReason::http_response_says_fatal_error;
×
613
            // If the connection fails/times out and the server has not been contacted yet, refresh the location
614
            // to make sure the websocket URL is correct
615
            if (!m_server_endpoint.is_verified) {
×
616
                error_info.server_requests_action = ProtocolErrorInfo::Action::RefreshLocation;
×
617
                reason = ConnectionTerminationReason::connect_operation_failed;
×
618
            }
×
619
            involuntary_disconnect(std::move(error_info), reason);
×
620
            break;
×
621
        }
×
622
        case WebSocketError::websocket_forbidden: {
✔
623
            SessionErrorInfo error_info({ErrorCodes::AuthError, msg}, IsFatal{true});
×
624
            error_info.server_requests_action = ProtocolErrorInfo::Action::LogOutUser;
×
625
            involuntary_disconnect(std::move(error_info),
×
626
                                   ConnectionTerminationReason::http_response_says_fatal_error);
×
627
            break;
×
628
        }
×
629
        case WebSocketError::websocket_unauthorized: {
44✔
630
            SessionErrorInfo error_info(
44✔
631
                {ErrorCodes::AuthError,
44✔
632
                 util::format("Websocket was closed because of an authentication issue: %1", msg)},
44✔
633
                IsFatal{false});
44✔
634
            error_info.server_requests_action = ProtocolErrorInfo::Action::RefreshUser;
44✔
635
            involuntary_disconnect(std::move(error_info),
44✔
636
                                   ConnectionTerminationReason::http_response_says_nonfatal_error);
44✔
637
            break;
44✔
638
        }
×
639
        case WebSocketError::websocket_moved_permanently: {
12✔
640
            SessionErrorInfo error_info({ErrorCodes::ConnectionClosed, msg}, IsFatal{false});
12✔
641
            error_info.server_requests_action = ProtocolErrorInfo::Action::RefreshLocation;
12✔
642
            involuntary_disconnect(std::move(error_info),
12✔
643
                                   ConnectionTerminationReason::http_response_says_nonfatal_error);
12✔
644
            break;
12✔
645
        }
×
646
        case WebSocketError::websocket_abnormal_closure: {
✔
647
            SessionErrorInfo error_info({ErrorCodes::ConnectionClosed, msg}, IsFatal{false});
×
648
            error_info.server_requests_action = ProtocolErrorInfo::Action::RefreshUser;
×
649
            involuntary_disconnect(std::move(error_info),
×
650
                                   ConnectionTerminationReason::http_response_says_nonfatal_error);
×
651
            break;
×
652
        }
×
653
        case WebSocketError::websocket_internal_server_error:
✔
654
            [[fallthrough]];
×
655
        case WebSocketError::websocket_retry_error: {
✔
656
            involuntary_disconnect(SessionErrorInfo({ErrorCodes::ConnectionClosed, msg}, IsFatal{false}),
×
657
                                   ConnectionTerminationReason::http_response_says_nonfatal_error);
×
658
            break;
×
659
        }
×
660
    }
816✔
661

662
    return bool(m_websocket);
804✔
663
}
816✔
664

665
// Guarantees that handle_reconnect_wait() is never called from within the
666
// execution of initiate_reconnect_wait() (no callback reentrance).
667
void Connection::initiate_reconnect_wait()
668
{
8,452✔
669
    REALM_ASSERT(m_activated);
8,452✔
670
    REALM_ASSERT(!m_reconnect_delay_in_progress);
8,452✔
671
    REALM_ASSERT(!m_disconnect_delay_in_progress);
8,452✔
672

673
    // If we've been force closed then we don't need/want to reconnect. Just return early here.
674
    if (m_force_closed) {
8,452✔
675
        return;
2,428✔
676
    }
2,428✔
677

678
    m_reconnect_delay_in_progress = true;
6,024✔
679
    auto delay = m_reconnect_info.delay_interval();
6,024✔
680
    if (delay == std::chrono::milliseconds::max()) {
6,024✔
681
        logger.detail("Reconnection delayed indefinitely"); // Throws
1,000✔
682
        // Not actually starting a timer corresponds to an infinite wait
683
        m_nonzero_reconnect_delay = true;
1,000✔
684
        return;
1,000✔
685
    }
1,000✔
686

687
    if (delay == std::chrono::milliseconds::zero()) {
5,024✔
688
        m_nonzero_reconnect_delay = false;
4,694✔
689
    }
4,694✔
690
    else {
330✔
691
        logger.detail("Allowing reconnection in %1 milliseconds", delay.count()); // Throws
330✔
692
        m_nonzero_reconnect_delay = true;
330✔
693
    }
330✔
694

695
    // We create a timer for the reconnect_disconnect timer even if the delay is zero because
696
    // we need it to be cancelable in case the connection is terminated before the timer
697
    // callback is run.
698
    m_reconnect_disconnect_timer = m_client.create_timer(delay, [this](Status status) {
5,028✔
699
        // If the operation is aborted, the connection object may have been
700
        // destroyed.
701
        if (status != ErrorCodes::OperationAborted)
5,028✔
702
            handle_reconnect_wait(status); // Throws
3,764✔
703
    });                                    // Throws
5,028✔
704
}
5,024✔
705

706

707
void Connection::handle_reconnect_wait(Status status)
708
{
3,766✔
709
    if (!status.is_ok()) {
3,766✔
710
        REALM_ASSERT(status != ErrorCodes::OperationAborted);
×
711
        throw Exception(status);
×
712
    }
×
713

714
    REALM_ASSERT(m_reconnect_delay_in_progress);
3,766✔
715
    m_reconnect_delay_in_progress = false;
3,766✔
716

717
    if (m_num_active_unsuspended_sessions > 0)
3,766✔
718
        initiate_reconnect(); // Throws
3,760✔
719
}
3,766✔
720

721
struct Connection::WebSocketObserverShim : public sync::WebSocketObserver {
722
    explicit WebSocketObserverShim(Connection* conn)
723
        : conn(conn)
1,784✔
724
        , sentinel(conn->m_websocket_sentinel)
1,784✔
725
    {
3,766✔
726
    }
3,766✔
727

728
    Connection* conn;
729
    util::bind_ptr<LifecycleSentinel> sentinel;
730

731
    void websocket_connected_handler(const std::string& protocol) override
732
    {
3,560✔
733
        if (sentinel->destroyed) {
3,560✔
734
            return;
×
735
        }
×
736

737
        return conn->websocket_connected_handler(protocol);
3,560✔
738
    }
3,560✔
739

740
    void websocket_error_handler() override
741
    {
712✔
742
        if (sentinel->destroyed) {
712✔
743
            return;
×
744
        }
×
745

746
        conn->websocket_error_handler();
712✔
747
    }
712✔
748

749
    bool websocket_binary_message_received(util::Span<const char> data) override
750
    {
79,656✔
751
        if (sentinel->destroyed) {
79,656✔
752
            return false;
×
753
        }
×
754

755
        return conn->websocket_binary_message_received(data);
79,656✔
756
    }
79,656✔
757

758
    bool websocket_closed_handler(bool was_clean, WebSocketError error_code, std::string_view msg) override
759
    {
816✔
760
        if (sentinel->destroyed) {
816✔
761
            return true;
×
762
        }
×
763

764
        return conn->websocket_closed_handler(was_clean, error_code, msg);
816✔
765
    }
816✔
766
};
767

768
void Connection::initiate_reconnect()
769
{
3,764✔
770
    REALM_ASSERT(m_activated);
3,764✔
771

772
    m_state = ConnectionState::connecting;
3,764✔
773
    report_connection_state_change(ConnectionState::connecting); // Throws
3,764✔
774
    if (m_websocket_sentinel) {
3,764✔
775
        m_websocket_sentinel->destroyed = true;
×
776
    }
×
777
    m_websocket_sentinel = util::make_bind<LifecycleSentinel>();
3,764✔
778
    m_websocket.reset();
3,764✔
779

780
    // Watchdog
781
    initiate_connect_wait(); // Throws
3,764✔
782

783
    std::vector<std::string> sec_websocket_protocol;
3,764✔
784
    {
3,764✔
785
        auto protocol_prefix =
3,764✔
786
            is_flx_sync_connection() ? get_flx_websocket_protocol_prefix() : get_pbs_websocket_protocol_prefix();
3,764✔
787
        int min = get_oldest_supported_protocol_version();
3,764✔
788
        int max = get_current_protocol_version();
3,764✔
789
        REALM_ASSERT_3(min, <=, max);
3,764✔
790
        // List protocol version in descending order to ensure that the server
791
        // selects the highest possible version.
792
        for (int version = max; version >= min; --version) {
48,946✔
793
            sec_websocket_protocol.push_back(util::format("%1%2", protocol_prefix, version)); // Throws
45,182✔
794
        }
45,182✔
795
    }
3,764✔
796

797
    logger.info("Connecting to '%1%2:%3%4'", to_string(m_server_endpoint.envelope), m_server_endpoint.address,
3,764✔
798
                m_server_endpoint.port, m_http_request_path_prefix);
3,764✔
799

800
    m_websocket_error_received = false;
3,764✔
801
    m_websocket =
3,764✔
802
        m_client.m_socket_provider->connect(std::make_unique<WebSocketObserverShim>(this),
3,764✔
803
                                            WebSocketEndpoint{
3,764✔
804
                                                m_server_endpoint.address,
3,764✔
805
                                                m_server_endpoint.port,
3,764✔
806
                                                get_http_request_path(),
3,764✔
807
                                                std::move(sec_websocket_protocol),
3,764✔
808
                                                is_ssl(m_server_endpoint.envelope),
3,764✔
809
                                                /// DEPRECATED - The following will be removed in a future release
810
                                                {m_custom_http_headers.begin(), m_custom_http_headers.end()},
3,764✔
811
                                                m_verify_servers_ssl_certificate,
3,764✔
812
                                                m_ssl_trust_certificate_path,
3,764✔
813
                                                m_ssl_verify_callback,
3,764✔
814
                                                m_proxy_config,
3,764✔
815
                                            });
3,764✔
816
}
3,764✔
817

818

819
void Connection::initiate_connect_wait()
820
{
3,764✔
821
    // Deploy a watchdog to enforce an upper bound on the time it can take to
822
    // fully establish the connection (including SSL and WebSocket
823
    // handshakes). Without such a watchdog, connect operations could take very
824
    // long, or even indefinite time.
825
    milliseconds_type time = m_client.m_connect_timeout;
3,764✔
826

827
    m_connect_timer = m_client.create_timer(std::chrono::milliseconds(time), [this](Status status) {
3,764✔
828
        // If the operation is aborted, the connection object may have been
829
        // destroyed.
830
        if (status != ErrorCodes::OperationAborted)
3,754✔
831
            handle_connect_wait(status); // Throws
×
832
    });                                  // Throws
3,754✔
833
}
3,764✔
834

835

836
void Connection::handle_connect_wait(Status status)
837
{
×
838
    if (!status.is_ok()) {
×
839
        REALM_ASSERT(status != ErrorCodes::OperationAborted);
×
840
        throw Exception(status);
×
841
    }
×
842

843
    REALM_ASSERT_EX(m_state == ConnectionState::connecting, m_state);
×
844
    logger.info("Connect timeout"); // Throws
×
845
    SessionErrorInfo error_info({ErrorCodes::SyncConnectTimeout, "Sync connection was not fully established in time"},
×
846
                                IsFatal{false});
×
847
    // If the connection fails/times out and the server has not been contacted yet, refresh the location
848
    // to make sure the websocket URL is correct
849
    if (!m_server_endpoint.is_verified) {
×
850
        error_info.server_requests_action = ProtocolErrorInfo::Action::RefreshLocation;
×
851
    }
×
852
    involuntary_disconnect(std::move(error_info), ConnectionTerminationReason::sync_connect_timeout); // Throws
×
853
}
×
854

855

856
void Connection::handle_connection_established()
857
{
3,560✔
858
    // Cancel connect timeout watchdog
859
    m_connect_timer.reset();
3,560✔
860

861
    m_state = ConnectionState::connected;
3,560✔
862
    m_server_endpoint.is_verified = true; // sync route is valid since connection is successful
3,560✔
863

864
    milliseconds_type now = monotonic_clock_now();
3,560✔
865
    m_pong_wait_started_at = now; // Initially, no time was spent waiting for a PONG message
3,560✔
866
    initiate_ping_delay(now);     // Throws
3,560✔
867

868
    bool fast_reconnect = false;
3,560✔
869
    if (m_disconnect_has_occurred) {
3,560✔
870
        milliseconds_type time = now - m_disconnect_time;
1,026✔
871
        if (time <= m_client.m_fast_reconnect_limit)
1,026✔
872
            fast_reconnect = true;
1,026✔
873
    }
1,026✔
874

875
    for (auto& p : m_sessions) {
4,708✔
876
        Session& sess = *p.second;
4,708✔
877
        sess.connection_established(fast_reconnect); // Throws
4,708✔
878
    }
4,708✔
879

880
    report_connection_state_change(ConnectionState::connected); // Throws
3,560✔
881
}
3,560✔
882

883

884
void Connection::schedule_urgent_ping()
885
{
226✔
886
    REALM_ASSERT_EX(m_state != ConnectionState::disconnected, m_state);
226✔
887
    if (m_ping_delay_in_progress) {
226✔
888
        m_heartbeat_timer.reset();
94✔
889
        m_ping_delay_in_progress = false;
94✔
890
        m_minimize_next_ping_delay = true;
94✔
891
        milliseconds_type now = monotonic_clock_now();
94✔
892
        initiate_ping_delay(now); // Throws
94✔
893
        return;
94✔
894
    }
94✔
895
    REALM_ASSERT_EX(m_state == ConnectionState::connecting || m_waiting_for_pong, m_state);
132✔
896
    if (!m_send_ping)
132✔
897
        m_minimize_next_ping_delay = true;
132✔
898
}
132✔
899

900

901
void Connection::initiate_ping_delay(milliseconds_type now)
902
{
3,774✔
903
    REALM_ASSERT(!m_ping_delay_in_progress);
3,774✔
904
    REALM_ASSERT(!m_waiting_for_pong);
3,774✔
905
    REALM_ASSERT(!m_send_ping);
3,774✔
906

907
    milliseconds_type delay = 0;
3,774✔
908
    if (!m_minimize_next_ping_delay) {
3,774✔
909
        delay = m_client.m_ping_keepalive_period;
3,670✔
910
        // Make a randomized deduction of up to 10%, or up to 100% if this is
911
        // the first PING message to be sent since the connection was
912
        // established. The purpose of this randomized deduction is to reduce
913
        // the risk of many connections sending PING messages simultaneously to
914
        // the server.
915
        milliseconds_type max_deduction = (m_ping_sent ? delay / 10 : delay);
3,670✔
916
        auto distr = std::uniform_int_distribution<milliseconds_type>(0, max_deduction);
3,670✔
917
        milliseconds_type randomized_deduction = distr(m_client.get_random());
3,670✔
918
        delay -= randomized_deduction;
3,670✔
919
        // Deduct the time spent waiting for PONG
920
        REALM_ASSERT_3(now, >=, m_pong_wait_started_at);
3,670✔
921
        milliseconds_type spent_time = now - m_pong_wait_started_at;
3,670✔
922
        if (spent_time < delay) {
3,670✔
923
            delay -= spent_time;
3,662✔
924
        }
3,662✔
925
        else {
8✔
926
            delay = 0;
8✔
927
        }
8✔
928
    }
3,670✔
929
    else {
104✔
930
        m_minimize_next_ping_delay = false;
104✔
931
    }
104✔
932

933

934
    m_ping_delay_in_progress = true;
3,774✔
935

936
    m_heartbeat_timer = m_client.create_timer(std::chrono::milliseconds(delay), [this](Status status) {
3,774✔
937
        if (status == ErrorCodes::OperationAborted)
3,774✔
938
            return;
3,638✔
939
        else if (!status.is_ok())
136✔
940
            throw Exception(status);
×
941

942
        handle_ping_delay();                                    // Throws
136✔
943
    });                                                         // Throws
136✔
944
    logger.debug("Will emit a ping in %1 milliseconds", delay); // Throws
3,774✔
945
}
3,774✔
946

947

948
void Connection::handle_ping_delay()
949
{
136✔
950
    REALM_ASSERT(m_ping_delay_in_progress);
136✔
951
    m_ping_delay_in_progress = false;
136✔
952
    m_send_ping = true;
136✔
953

954
    initiate_pong_timeout(); // Throws
136✔
955

956
    if (m_state == ConnectionState::connected && !m_sending)
136✔
957
        send_next_message(); // Throws
90✔
958
}
136✔
959

960

961
void Connection::initiate_pong_timeout()
962
{
136✔
963
    REALM_ASSERT(!m_ping_delay_in_progress);
136✔
964
    REALM_ASSERT(!m_waiting_for_pong);
136✔
965
    REALM_ASSERT(m_send_ping);
136✔
966

967
    m_waiting_for_pong = true;
136✔
968
    m_pong_wait_started_at = monotonic_clock_now();
136✔
969

970
    milliseconds_type time = m_client.m_pong_keepalive_timeout;
136✔
971
    m_heartbeat_timer = m_client.create_timer(std::chrono::milliseconds(time), [this](Status status) {
136✔
972
        if (status == ErrorCodes::OperationAborted)
136✔
973
            return;
124✔
974
        else if (!status.is_ok())
12✔
975
            throw Exception(status);
×
976

977
        handle_pong_timeout(); // Throws
12✔
978
    });                        // Throws
12✔
979
}
136✔
980

981

982
void Connection::handle_pong_timeout()
983
{
12✔
984
    REALM_ASSERT(m_waiting_for_pong);
12✔
985
    logger.debug("Timeout on reception of PONG message"); // Throws
12✔
986
    close_due_to_transient_error({ErrorCodes::ConnectionClosed, "Timed out waiting for PONG response from server"},
12✔
987
                                 ConnectionTerminationReason::pong_timeout);
12✔
988
}
12✔
989

990

991
void Connection::initiate_write_message(const OutputBuffer& out, Session* sess)
992
{
99,022✔
993
    // Stop sending messages if an websocket error was received.
994
    if (m_websocket_error_received)
99,022✔
995
        return;
×
996

997
    m_websocket->async_write_binary(out.as_span(), [this, sentinel = m_websocket_sentinel](Status status) {
99,022✔
998
        if (sentinel->destroyed) {
98,940✔
999
            return;
1,426✔
1000
        }
1,426✔
1001
        if (!status.is_ok()) {
97,514✔
1002
            if (status != ErrorCodes::Error::OperationAborted) {
×
1003
                // Write errors will be handled by the websocket_write_error_handler() callback
1004
                logger.error("Connection: write failed %1: %2", status.code_string(), status.reason());
×
1005
            }
×
1006
            return;
×
1007
        }
×
1008
        handle_write_message(); // Throws
97,514✔
1009
    });                         // Throws
97,514✔
1010
    m_sending_session = sess;
99,022✔
1011
    m_sending = true;
99,022✔
1012
}
99,022✔
1013

1014

1015
void Connection::handle_write_message()
1016
{
97,510✔
1017
    m_sending_session->message_sent(); // Throws
97,510✔
1018
    if (m_sending_session->m_state == Session::Deactivated) {
97,510✔
1019
        finish_session_deactivation(m_sending_session);
130✔
1020
    }
130✔
1021
    m_sending_session = nullptr;
97,510✔
1022
    m_sending = false;
97,510✔
1023
    send_next_message(); // Throws
97,510✔
1024
}
97,510✔
1025

1026

1027
void Connection::send_next_message()
1028
{
162,424✔
1029
    REALM_ASSERT_EX(m_state == ConnectionState::connected, m_state);
162,424✔
1030
    REALM_ASSERT(!m_sending_session);
162,424✔
1031
    REALM_ASSERT(!m_sending);
162,424✔
1032
    if (m_send_ping) {
162,424✔
1033
        send_ping(); // Throws
124✔
1034
        return;
124✔
1035
    }
124✔
1036
    while (!m_sessions_enlisted_to_send.empty()) {
228,138✔
1037
        // The state of being connected is not supposed to be able to change
1038
        // across this loop thanks to the "no callback reentrance" guarantee
1039
        // provided by Websocket::async_write_text(), and friends.
1040
        REALM_ASSERT_EX(m_state == ConnectionState::connected, m_state);
165,126✔
1041

1042
        Session& sess = *m_sessions_enlisted_to_send.front();
165,126✔
1043
        m_sessions_enlisted_to_send.pop_front();
165,126✔
1044
        sess.send_message(); // Throws
165,126✔
1045

1046
        if (sess.m_state == Session::Deactivated) {
165,126✔
1047
            finish_session_deactivation(&sess);
2,896✔
1048
        }
2,896✔
1049

1050
        // An enlisted session may choose to not send a message. In that case,
1051
        // we should pass the opportunity to the next enlisted session.
1052
        if (m_sending)
165,126✔
1053
            break;
99,288✔
1054
    }
165,126✔
1055
}
162,300✔
1056

1057

1058
void Connection::send_ping()
1059
{
124✔
1060
    REALM_ASSERT(!m_ping_delay_in_progress);
124✔
1061
    REALM_ASSERT(m_waiting_for_pong);
124✔
1062
    REALM_ASSERT(m_send_ping);
124✔
1063

1064
    m_send_ping = false;
124✔
1065
    if (m_reconnect_info.scheduled_reset)
124✔
1066
        m_ping_after_scheduled_reset_of_reconnect_info = true;
98✔
1067

1068
    m_last_ping_sent_at = monotonic_clock_now();
124✔
1069
    logger.debug("Sending: PING(timestamp=%1, rtt=%2)", m_last_ping_sent_at,
124✔
1070
                 m_previous_ping_rtt); // Throws
124✔
1071

1072
    ClientProtocol& protocol = get_client_protocol();
124✔
1073
    OutputBuffer& out = get_output_buffer();
124✔
1074
    protocol.make_ping(out, m_last_ping_sent_at, m_previous_ping_rtt); // Throws
124✔
1075
    initiate_write_ping(out);                                          // Throws
124✔
1076
    m_ping_sent = true;
124✔
1077
}
124✔
1078

1079

1080
void Connection::initiate_write_ping(const OutputBuffer& out)
1081
{
124✔
1082
    m_websocket->async_write_binary(out.as_span(), [this, sentinel = m_websocket_sentinel](Status status) {
124✔
1083
        if (sentinel->destroyed) {
124✔
1084
            return;
2✔
1085
        }
2✔
1086
        if (!status.is_ok()) {
122✔
1087
            if (status != ErrorCodes::Error::OperationAborted) {
×
1088
                // Write errors will be handled by the websocket_write_error_handler() callback
1089
                logger.error("Connection: send ping failed %1: %2", status.code_string(), status.reason());
×
1090
            }
×
1091
            return;
×
1092
        }
×
1093
        handle_write_ping(); // Throws
122✔
1094
    });                      // Throws
122✔
1095
    m_sending = true;
124✔
1096
}
124✔
1097

1098

1099
void Connection::handle_write_ping()
1100
{
122✔
1101
    REALM_ASSERT(m_sending);
122✔
1102
    REALM_ASSERT(!m_sending_session);
122✔
1103
    m_sending = false;
122✔
1104
    send_next_message(); // Throws
122✔
1105
}
122✔
1106

1107

1108
void Connection::handle_message_received(util::Span<const char> data)
1109
{
79,218✔
1110
    // parse_message_received() parses the message and calls the proper handler
1111
    // on the Connection object (this).
1112
    get_client_protocol().parse_message_received<Connection>(*this, std::string_view(data.data(), data.size()));
79,218✔
1113
}
79,218✔
1114

1115

1116
void Connection::initiate_disconnect_wait()
1117
{
4,348✔
1118
    REALM_ASSERT(!m_reconnect_delay_in_progress);
4,348✔
1119

1120
    if (m_disconnect_delay_in_progress) {
4,348✔
1121
        m_reconnect_disconnect_timer.reset();
1,836✔
1122
        m_disconnect_delay_in_progress = false;
1,836✔
1123
    }
1,836✔
1124

1125
    milliseconds_type time = m_client.m_connection_linger_time;
4,348✔
1126

1127
    m_reconnect_disconnect_timer = m_client.create_timer(std::chrono::milliseconds(time), [this](Status status) {
4,348✔
1128
        // If the operation is aborted, the connection object may have been
1129
        // destroyed.
1130
        if (status != ErrorCodes::OperationAborted)
4,346✔
1131
            handle_disconnect_wait(status); // Throws
12✔
1132
    });                                     // Throws
4,346✔
1133
    m_disconnect_delay_in_progress = true;
4,348✔
1134
}
4,348✔
1135

1136

1137
void Connection::handle_disconnect_wait(Status status)
1138
{
12✔
1139
    if (!status.is_ok()) {
12✔
1140
        REALM_ASSERT(status != ErrorCodes::OperationAborted);
×
1141
        throw Exception(status);
×
1142
    }
×
1143

1144
    m_disconnect_delay_in_progress = false;
12✔
1145

1146
    REALM_ASSERT_EX(m_state != ConnectionState::disconnected, m_state);
12✔
1147
    if (m_num_active_unsuspended_sessions == 0) {
12✔
1148
        if (m_client.m_connection_linger_time > 0)
12✔
1149
            logger.detail("Linger time expired"); // Throws
×
1150
        voluntary_disconnect();                   // Throws
12✔
1151
        logger.info("Disconnected");              // Throws
12✔
1152
    }
12✔
1153
}
12✔
1154

1155

1156
void Connection::close_due_to_protocol_error(Status status)
1157
{
16✔
1158
    SessionErrorInfo error_info(std::move(status), IsFatal{true});
16✔
1159
    error_info.server_requests_action = ProtocolErrorInfo::Action::ProtocolViolation;
16✔
1160
    involuntary_disconnect(std::move(error_info),
16✔
1161
                           ConnectionTerminationReason::sync_protocol_violation); // Throws
16✔
1162
}
16✔
1163

1164

1165
void Connection::close_due_to_client_side_error(Status status, IsFatal is_fatal, ConnectionTerminationReason reason)
1166
{
444✔
1167
    logger.info("Connection closed due to error: %1", status); // Throws
444✔
1168

1169
    involuntary_disconnect(SessionErrorInfo{std::move(status), is_fatal}, reason); // Throw
444✔
1170
}
444✔
1171

1172

1173
void Connection::close_due_to_transient_error(Status status, ConnectionTerminationReason reason)
1174
{
590✔
1175
    logger.info("Connection closed due to transient error: %1", status); // Throws
590✔
1176
    SessionErrorInfo error_info{std::move(status), IsFatal{false}};
590✔
1177
    error_info.server_requests_action = ProtocolErrorInfo::Action::Transient;
590✔
1178

1179
    involuntary_disconnect(std::move(error_info), reason); // Throw
590✔
1180
}
590✔
1181

1182

1183
// Close connection due to error discovered on the server-side, and then
1184
// reported to the client by way of a connection-level ERROR message.
1185
void Connection::close_due_to_server_side_error(ProtocolError error_code, const ProtocolErrorInfo& info)
1186
{
68✔
1187
    logger.info("Connection closed due to error reported by server: %1 (%2)", info.message,
68✔
1188
                int(error_code)); // Throws
68✔
1189

1190
    const auto reason = info.is_fatal ? ConnectionTerminationReason::server_said_do_not_reconnect
68✔
1191
                                      : ConnectionTerminationReason::server_said_try_again_later;
68✔
1192
    involuntary_disconnect(SessionErrorInfo{info, protocol_error_to_status(error_code, info.message)},
68✔
1193
                           reason); // Throws
68✔
1194
}
68✔
1195

1196

1197
void Connection::disconnect(const SessionErrorInfo& info)
1198
{
3,766✔
1199
    // Cancel connect timeout watchdog
1200
    m_connect_timer.reset();
3,766✔
1201

1202
    if (m_state == ConnectionState::connected) {
3,766✔
1203
        m_disconnect_time = monotonic_clock_now();
3,558✔
1204
        m_disconnect_has_occurred = true;
3,558✔
1205

1206
        // Sessions that are in the Deactivating state at this time can be
1207
        // immediately discarded, in part because they are no longer enlisted to
1208
        // send. Such sessions will be taken to the Deactivated state by
1209
        // Session::connection_lost(), and then they will be removed from
1210
        // `m_sessions`.
1211
        auto i = m_sessions.begin(), end = m_sessions.end();
3,558✔
1212
        while (i != end) {
8,024✔
1213
            // Prevent invalidation of the main iterator when erasing elements
1214
            auto j = i++;
4,466✔
1215
            Session& sess = *j->second;
4,466✔
1216
            sess.connection_lost(); // Throws
4,466✔
1217
            if (sess.m_state == Session::Unactivated || sess.m_state == Session::Deactivated)
4,468✔
1218
                m_sessions.erase(j);
2,320✔
1219
        }
4,466✔
1220
    }
3,558✔
1221

1222
    change_state_to_disconnected();
3,766✔
1223

1224
    m_ping_delay_in_progress = false;
3,766✔
1225
    m_waiting_for_pong = false;
3,766✔
1226
    m_send_ping = false;
3,766✔
1227
    m_minimize_next_ping_delay = false;
3,766✔
1228
    m_ping_after_scheduled_reset_of_reconnect_info = false;
3,766✔
1229
    m_ping_sent = false;
3,766✔
1230
    m_heartbeat_timer.reset();
3,766✔
1231
    m_previous_ping_rtt = 0;
3,766✔
1232

1233
    m_websocket_sentinel->destroyed = true;
3,766✔
1234
    m_websocket_sentinel.reset();
3,766✔
1235
    m_websocket.reset();
3,766✔
1236
    m_input_body_buffer.reset();
3,766✔
1237
    m_sending_session = nullptr;
3,766✔
1238
    m_sessions_enlisted_to_send.clear();
3,766✔
1239
    m_sending = false;
3,766✔
1240

1241
    report_connection_state_change(ConnectionState::disconnected, info); // Throws
3,766✔
1242
    initiate_reconnect_wait();                                           // Throws
3,766✔
1243
}
3,766✔
1244

1245
bool Connection::is_flx_sync_connection() const noexcept
1246
{
113,560✔
1247
    return m_server_endpoint.server_mode != SyncServerMode::PBS;
113,560✔
1248
}
113,560✔
1249

1250
void Connection::receive_pong(milliseconds_type timestamp)
1251
{
120✔
1252
    logger.debug("Received: PONG(timestamp=%1)", timestamp);
120✔
1253

1254
    bool legal_at_this_time = (m_waiting_for_pong && !m_send_ping);
120✔
1255
    if (REALM_UNLIKELY(!legal_at_this_time)) {
120✔
1256
        close_due_to_protocol_error(
×
1257
            {ErrorCodes::SyncProtocolInvariantFailed, "Received PONG message when it was not valid"}); // Throws
×
1258
        return;
×
1259
    }
×
1260

1261
    if (REALM_UNLIKELY(timestamp != m_last_ping_sent_at)) {
120✔
1262
        close_due_to_protocol_error(
×
1263
            {ErrorCodes::SyncProtocolInvariantFailed,
×
1264
             util::format("Received PONG message with an invalid timestamp (expected %1, received %2)",
×
1265
                          m_last_ping_sent_at, timestamp)}); // Throws
×
1266
        return;
×
1267
    }
×
1268

1269
    milliseconds_type now = monotonic_clock_now();
120✔
1270
    milliseconds_type round_trip_time = now - timestamp;
120✔
1271
    logger.debug("Round trip time was %1 milliseconds", round_trip_time);
120✔
1272
    m_previous_ping_rtt = round_trip_time;
120✔
1273

1274
    // If this PONG message is a response to a PING mesage that was sent after
1275
    // the last invocation of cancel_reconnect_delay(), then the connection is
1276
    // still good, and we do not have to skip the next reconnect delay.
1277
    if (m_ping_after_scheduled_reset_of_reconnect_info) {
120✔
1278
        REALM_ASSERT(m_reconnect_info.scheduled_reset);
84✔
1279
        m_ping_after_scheduled_reset_of_reconnect_info = false;
84✔
1280
        m_reconnect_info.scheduled_reset = false;
84✔
1281
    }
84✔
1282

1283
    m_heartbeat_timer.reset();
120✔
1284
    m_waiting_for_pong = false;
120✔
1285

1286
    initiate_ping_delay(now); // Throws
120✔
1287

1288
    if (m_client.m_roundtrip_time_handler)
120✔
1289
        m_client.m_roundtrip_time_handler(m_previous_ping_rtt); // Throws
×
1290
}
120✔
1291

1292
Session* Connection::find_and_validate_session(session_ident_type session_ident, std::string_view message) noexcept
1293
{
73,132✔
1294
    if (session_ident == 0) {
73,132✔
1295
        return nullptr;
×
1296
    }
×
1297

1298
    auto* sess = get_session(session_ident);
73,132✔
1299
    if (REALM_LIKELY(sess)) {
73,132✔
1300
        return sess;
73,132✔
1301
    }
73,132✔
1302
    // Check the history to see if the message received was for a previous session
UNCOV
1303
    if (auto it = m_session_history.find(session_ident); it == m_session_history.end()) {
×
1304
        logger.error("Bad session identifier in %1 message, session_ident = %2", message, session_ident);
×
1305
        close_due_to_protocol_error(
×
1306
            {ErrorCodes::SyncProtocolInvariantFailed,
×
1307
             util::format("Received message %1 for session iden %2 when that session never existed", message,
×
1308
                          session_ident)});
×
1309
    }
×
UNCOV
1310
    else {
×
UNCOV
1311
        logger.error("Received %1 message for closed session, session_ident = %2", message,
×
UNCOV
1312
                     session_ident); // Throws
×
UNCOV
1313
    }
×
UNCOV
1314
    return nullptr;
×
1315
}
73,132✔
1316

1317
void Connection::receive_error_message(const ProtocolErrorInfo& info, session_ident_type session_ident)
1318
{
770✔
1319
    Session* sess = nullptr;
770✔
1320
    if (session_ident != 0) {
770✔
1321
        sess = find_and_validate_session(session_ident, "ERROR");
698✔
1322
        if (REALM_UNLIKELY(!sess)) {
698✔
1323
            return;
×
1324
        }
×
1325
        if (auto status = sess->receive_error_message(info); !status.is_ok()) {
698✔
1326
            close_due_to_protocol_error(std::move(status)); // Throws
×
1327
            return;
×
1328
        }
×
1329

1330
        if (sess->m_state == Session::Deactivated) {
698✔
1331
            finish_session_deactivation(sess);
×
1332
        }
×
1333
        return;
698✔
1334
    }
698✔
1335

1336
    logger.info("Received: ERROR \"%1\" (error_code=%2, is_fatal=%3, session_ident=%4, error_action=%5)",
72✔
1337
                info.message, info.raw_error_code, info.is_fatal, session_ident,
72✔
1338
                info.server_requests_action); // Throws
72✔
1339

1340
    bool known_error_code = bool(get_protocol_error_message(info.raw_error_code));
72✔
1341
    if (REALM_LIKELY(known_error_code)) {
72✔
1342
        ProtocolError error_code = ProtocolError(info.raw_error_code);
68✔
1343
        if (REALM_LIKELY(!is_session_level_error(error_code))) {
68✔
1344
            close_due_to_server_side_error(error_code, info); // Throws
68✔
1345
            return;
68✔
1346
        }
68✔
1347
        close_due_to_protocol_error(
×
1348
            {ErrorCodes::SyncProtocolInvariantFailed,
×
1349
             util::format("Received ERROR message with a non-connection-level error code %1 without a session ident",
×
1350
                          info.raw_error_code)});
×
1351
    }
×
1352
    else {
4✔
1353
        close_due_to_protocol_error(
4✔
1354
            {ErrorCodes::SyncProtocolInvariantFailed,
4✔
1355
             util::format("Received ERROR message with unknown error code %1", info.raw_error_code)});
4✔
1356
    }
4✔
1357
}
72✔
1358

1359

1360
void Connection::receive_query_error_message(int raw_error_code, std::string_view message, int64_t query_version,
1361
                                             session_ident_type session_ident)
1362
{
20✔
1363
    if (session_ident == 0) {
20✔
1364
        return close_due_to_protocol_error(
×
1365
            {ErrorCodes::SyncProtocolInvariantFailed, "Received query error message for session ident 0"});
×
1366
    }
×
1367

1368
    if (!is_flx_sync_connection()) {
20✔
1369
        return close_due_to_protocol_error({ErrorCodes::SyncProtocolInvariantFailed,
×
1370
                                            "Received a FLX query error message on a non-FLX sync connection"});
×
1371
    }
×
1372

1373
    Session* sess = find_and_validate_session(session_ident, "QUERY_ERROR");
20✔
1374
    if (REALM_UNLIKELY(!sess)) {
20✔
1375
        return;
×
1376
    }
×
1377

1378
    if (auto status = sess->receive_query_error_message(raw_error_code, message, query_version); !status.is_ok()) {
20✔
1379
        close_due_to_protocol_error(std::move(status));
×
1380
    }
×
1381
}
20✔
1382

1383

1384
void Connection::receive_ident_message(session_ident_type session_ident, SaltedFileIdent client_file_ident)
1385
{
3,768✔
1386
    Session* sess = find_and_validate_session(session_ident, "IDENT");
3,768✔
1387
    if (REALM_UNLIKELY(!sess)) {
3,768✔
1388
        return;
×
1389
    }
×
1390

1391
    if (auto status = sess->receive_ident_message(client_file_ident); !status.is_ok())
3,768✔
1392
        close_due_to_protocol_error(std::move(status)); // Throws
×
1393
}
3,768✔
1394

1395
void Connection::receive_download_message(session_ident_type session_ident, const DownloadMessage& message)
1396
{
48,414✔
1397
    Session* sess = find_and_validate_session(session_ident, "DOWNLOAD");
48,414✔
1398
    if (REALM_UNLIKELY(!sess)) {
48,414✔
1399
        return;
×
1400
    }
×
1401

1402
    if (auto status = sess->receive_download_message(message); !status.is_ok()) {
48,414✔
1403
        close_due_to_protocol_error(std::move(status));
×
1404
    }
×
1405
}
48,414✔
1406

1407
void Connection::receive_mark_message(session_ident_type session_ident, request_ident_type request_ident)
1408
{
16,382✔
1409
    Session* sess = find_and_validate_session(session_ident, "MARK");
16,382✔
1410
    if (REALM_UNLIKELY(!sess)) {
16,382✔
1411
        return;
×
1412
    }
×
1413

1414
    if (auto status = sess->receive_mark_message(request_ident); !status.is_ok())
16,382✔
1415
        close_due_to_protocol_error(std::move(status)); // Throws
12✔
1416
}
16,382✔
1417

1418

1419
void Connection::receive_unbound_message(session_ident_type session_ident)
1420
{
3,798✔
1421
    Session* sess = find_and_validate_session(session_ident, "UNBOUND");
3,798✔
1422
    if (REALM_UNLIKELY(!sess)) {
3,798✔
1423
        return;
×
1424
    }
×
1425

1426
    if (auto status = sess->receive_unbound_message(); !status.is_ok()) {
3,798✔
1427
        close_due_to_protocol_error(std::move(status)); // Throws
×
1428
        return;
×
1429
    }
×
1430

1431
    if (sess->m_state == Session::Deactivated) {
3,798✔
1432
        finish_session_deactivation(sess);
3,798✔
1433
    }
3,798✔
1434
}
3,798✔
1435

1436

1437
void Connection::receive_test_command_response(session_ident_type session_ident, request_ident_type request_ident,
1438
                                               std::string_view body)
1439
{
52✔
1440
    Session* sess = find_and_validate_session(session_ident, "TEST_COMMAND");
52✔
1441
    if (REALM_UNLIKELY(!sess)) {
52✔
1442
        return;
×
1443
    }
×
1444

1445
    if (auto status = sess->receive_test_command_response(request_ident, body); !status.is_ok()) {
52✔
1446
        close_due_to_protocol_error(std::move(status));
×
1447
    }
×
1448
}
52✔
1449

1450

1451
void Connection::receive_server_log_message(session_ident_type session_ident, util::Logger::Level level,
1452
                                            std::string_view message)
1453
{
5,898✔
1454
    std::string prefix;
5,898✔
1455
    if (REALM_LIKELY(!m_appservices_coid.empty())) {
5,898✔
1456
        prefix = util::format("Server[%1]", m_appservices_coid);
5,898✔
1457
    }
5,898✔
1458
    else {
×
1459
        prefix = "Server";
×
1460
    }
×
1461

1462
    if (session_ident != 0) {
5,898✔
1463
        if (auto sess = get_session(session_ident)) {
3,916✔
1464
            sess->logger.log(LogCategory::session, level, "%1 log: %2", prefix, message);
3,902✔
1465
            return;
3,902✔
1466
        }
3,902✔
1467

1468
        logger.log(util::LogCategory::session, level, "%1 log for unknown session %2: %3", prefix, session_ident,
14✔
1469
                   message);
14✔
1470
        return;
14✔
1471
    }
3,916✔
1472

1473
    logger.log(level, "%1 log: %2", prefix, message);
1,982✔
1474
}
1,982✔
1475

1476

1477
void Connection::receive_appservices_request_id(std::string_view coid)
1478
{
5,540✔
1479
    // Only set once per connection
1480
    if (!coid.empty() && m_appservices_coid.empty()) {
5,540✔
1481
        m_appservices_coid = coid;
2,512✔
1482
        logger.log(util::LogCategory::session, util::LogCategory::Level::info,
2,512✔
1483
                   "Connected to app services with request id: \"%1\"", m_appservices_coid);
2,512✔
1484
    }
2,512✔
1485
}
5,540✔
1486

1487

1488
void Connection::handle_protocol_error(Status status)
1489
{
×
1490
    close_due_to_protocol_error(std::move(status));
×
1491
}
×
1492

1493

1494
// Sessions are guaranteed to be granted the opportunity to send a message in
1495
// the order that they enlist. Note that this is important to ensure
1496
// nonoverlapping communication with the server for consecutive sessions
1497
// associated with the same Realm file.
1498
//
1499
// CAUTION: The specified session may get destroyed before this function
1500
// returns, but only if its Session::send_message() puts it into the Deactivated
1501
// state.
1502
void Connection::enlist_to_send(Session* sess)
1503
{
166,680✔
1504
    REALM_ASSERT_EX(m_state == ConnectionState::connected, m_state);
166,680✔
1505
    m_sessions_enlisted_to_send.push_back(sess); // Throws
166,680✔
1506
    if (!m_sending)
166,680✔
1507
        send_next_message(); // Throws
64,700✔
1508
}
166,680✔
1509

1510

1511
std::string Connection::get_active_appservices_connection_id()
1512
{
72✔
1513
    return m_appservices_coid;
72✔
1514
}
72✔
1515

1516
void Session::cancel_resumption_delay()
1517
{
4,070✔
1518
    REALM_ASSERT_EX(m_state == Active, m_state);
4,070✔
1519

1520
    if (!m_suspended)
4,070✔
1521
        return;
4,010✔
1522

1523
    m_suspended = false;
60✔
1524

1525
    logger.debug("Resumed"); // Throws
60✔
1526

1527
    if (unbind_process_complete())
60✔
1528
        initiate_rebind(); // Throws
36✔
1529

1530
    m_conn.one_more_active_unsuspended_session(); // Throws
60✔
1531
    if (m_try_again_activation_timer) {
60✔
1532
        m_try_again_activation_timer.reset();
8✔
1533
    }
8✔
1534

1535
    on_resumed(); // Throws
60✔
1536
}
60✔
1537

1538

1539
void Session::gather_pending_compensating_writes(util::Span<Changeset> changesets,
1540
                                                 std::vector<ProtocolErrorInfo>* out)
1541
{
23,768✔
1542
    if (m_pending_compensating_write_errors.empty() || changesets.empty()) {
23,768✔
1543
        return;
23,724✔
1544
    }
23,724✔
1545

1546
#ifdef REALM_DEBUG
44✔
1547
    REALM_ASSERT_DEBUG(
44✔
1548
        std::is_sorted(m_pending_compensating_write_errors.begin(), m_pending_compensating_write_errors.end(),
44✔
1549
                       [](const ProtocolErrorInfo& lhs, const ProtocolErrorInfo& rhs) {
44✔
1550
                           REALM_ASSERT_DEBUG(lhs.compensating_write_server_version.has_value());
44✔
1551
                           REALM_ASSERT_DEBUG(rhs.compensating_write_server_version.has_value());
44✔
1552
                           return *lhs.compensating_write_server_version < *rhs.compensating_write_server_version;
44✔
1553
                       }));
44✔
1554
#endif
44✔
1555

1556
    while (!m_pending_compensating_write_errors.empty() &&
88✔
1557
           *m_pending_compensating_write_errors.front().compensating_write_server_version <=
88✔
1558
               changesets.back().version) {
44✔
1559
        auto& cur_error = m_pending_compensating_write_errors.front();
44✔
1560
        REALM_ASSERT_3(*cur_error.compensating_write_server_version, >=, changesets.front().version);
44✔
1561
        out->push_back(std::move(cur_error));
44✔
1562
        m_pending_compensating_write_errors.pop_front();
44✔
1563
    }
44✔
1564
}
44✔
1565

1566

1567
void Session::integrate_changesets(const SyncProgress& progress, std::uint_fast64_t downloadable_bytes,
1568
                                   const ReceivedChangesets& received_changesets, VersionInfo& version_info,
1569
                                   DownloadBatchState download_batch_state)
1570
{
45,608✔
1571
    auto& history = get_history();
45,608✔
1572
    if (received_changesets.empty()) {
45,608✔
1573
        if (download_batch_state == DownloadBatchState::MoreToCome) {
21,812✔
1574
            throw IntegrationException(ErrorCodes::SyncProtocolInvariantFailed,
×
1575
                                       "received empty download message that was not the last in batch",
×
1576
                                       ProtocolError::bad_progress);
×
1577
        }
×
1578
        history.set_sync_progress(progress, downloadable_bytes, version_info); // Throws
21,812✔
1579
        return;
21,812✔
1580
    }
21,812✔
1581

1582
    std::vector<ProtocolErrorInfo> pending_compensating_write_errors;
23,796✔
1583
    auto transact = get_db()->start_read();
23,796✔
1584
    history.integrate_server_changesets(
23,796✔
1585
        progress, downloadable_bytes, received_changesets, version_info, download_batch_state, logger, transact,
23,796✔
1586
        [&](const TransactionRef&, util::Span<Changeset> changesets) {
23,796✔
1587
            gather_pending_compensating_writes(changesets, &pending_compensating_write_errors);
23,768✔
1588
        }); // Throws
23,768✔
1589
    if (received_changesets.size() == 1) {
23,796✔
1590
        logger.debug("1 remote changeset integrated, producing client version %1",
15,490✔
1591
                     version_info.sync_version.version); // Throws
15,490✔
1592
    }
15,490✔
1593
    else {
8,306✔
1594
        logger.debug("%2 remote changesets integrated, producing client version %1",
8,306✔
1595
                     version_info.sync_version.version, received_changesets.size()); // Throws
8,306✔
1596
    }
8,306✔
1597

1598
    for (const auto& pending_error : pending_compensating_write_errors) {
23,796✔
1599
        logger.info("Reporting compensating write for client version %1 in server version %2: %3",
44✔
1600
                    pending_error.compensating_write_rejected_client_version,
44✔
1601
                    *pending_error.compensating_write_server_version, pending_error.message);
44✔
1602
        try {
44✔
1603
            on_connection_state_changed(
44✔
1604
                m_conn.get_state(),
44✔
1605
                SessionErrorInfo{pending_error,
44✔
1606
                                 protocol_error_to_status(static_cast<ProtocolError>(pending_error.raw_error_code),
44✔
1607
                                                          pending_error.message)});
44✔
1608
        }
44✔
1609
        catch (...) {
44✔
1610
            logger.error("Exception thrown while reporting compensating write: %1", exception_to_status());
×
1611
        }
×
1612
    }
44✔
1613
}
23,796✔
1614

1615

1616
void Session::on_integration_failure(const IntegrationException& error)
1617
{
40✔
1618
    REALM_ASSERT_EX(m_state == Active, m_state);
40✔
1619
    REALM_ASSERT(!m_client_error && !m_error_to_send);
40✔
1620
    logger.error("Failed to integrate downloaded changesets: %1", error.to_status());
40✔
1621

1622
    m_client_error = util::make_optional<IntegrationException>(error);
40✔
1623
    m_error_to_send = true;
40✔
1624
    SessionErrorInfo error_info{error.to_status(), IsFatal{false}};
40✔
1625
    error_info.server_requests_action = ProtocolErrorInfo::Action::Warning;
40✔
1626
    // Surface the error to the user otherwise is lost.
1627
    on_connection_state_changed(m_conn.get_state(), std::move(error_info));
40✔
1628

1629
    // Since the deactivation process has not been initiated, the UNBIND
1630
    // message cannot have been sent unless an ERROR message was received.
1631
    REALM_ASSERT(m_suspended || m_error_message_received || !m_unbind_message_sent);
40✔
1632
    if (m_ident_message_sent && !m_error_message_received && !m_suspended) {
40✔
1633
        ensure_enlisted_to_send(); // Throws
36✔
1634
    }
36✔
1635
}
40✔
1636

1637
void Session::on_changesets_integrated(version_type client_version, const SyncProgress& progress,
1638
                                       bool changesets_integrated)
21,822✔
1639
{
47,522✔
1640
    REALM_ASSERT_EX(m_state == Active, m_state);
47,522✔
1641
    REALM_ASSERT_3(progress.download.server_version, >=, m_download_progress.server_version);
25,700✔
1642
    bool upload_progressed = (progress.upload.client_version > m_progress.upload.client_version);
47,522✔
1643

21,822✔
1644
    m_download_progress = progress.download;
25,700✔
1645
    m_progress = progress;
47,522✔
1646

350✔
1647
    if (upload_progressed) {
25,700✔
1648
        if (progress.upload.client_version > m_last_version_selected_for_upload) {
39,962✔
1649
            if (progress.upload.client_version > m_upload_progress.client_version)
7,122✔
1650
                m_upload_progress = progress.upload;
22,148✔
1651
            m_last_version_selected_for_upload = progress.upload.client_version;
7,122✔
1652
        }
7,122✔
1653

21,822✔
1654
        notify_sync_progress();
19,756✔
1655
        check_for_upload_completion();
19,756✔
1656
    }
19,756✔
1657

1658
    bool resume_upload = do_recognize_sync_version(client_version); // Allows upload process to resume
25,700✔
1659

1660
    // notify also when final DOWNLOAD received with no changesets
21,822✔
1661
    bool download_progressed = changesets_integrated || (!upload_progressed && resume_upload);
47,522✔
1662
    if (download_progressed && !upload_progressed)
47,520✔
1663
        notify_sync_progress();
29,380✔
1664

21,822✔
1665
    check_for_download_completion(); // Throws
25,700✔
1666

1667
    // If the client migrated from PBS to FLX, create subscriptions when new tables are received from server.
1668
    if (auto migration_store = get_migration_store(); migration_store && m_is_flx_sync_session) {
30,546✔
1669
        auto& flx_subscription_store = *get_flx_subscription_store();
1,638✔
1670
        get_migration_store()->create_subscriptions(flx_subscription_store);
6,484✔
1671
    }
1,638✔
1672

1673
    // Since the deactivation process has not been initiated, the UNBIND
1674
    // message cannot have been sent unless an ERROR message was received.
4,854✔
1675
    REALM_ASSERT(m_suspended || m_error_message_received || !m_unbind_message_sent);
30,554✔
1676
    if (m_ident_message_sent && !m_error_message_received && !m_suspended) {
30,554✔
1677
        ensure_enlisted_to_send(); // Throws
30,550✔
1678
    }
30,550✔
1679
}
30,554✔
1680

1681

1682
Session::~Session()
1683
{
10,044✔
1684
    //    REALM_ASSERT_EX(m_state == Unactivated || m_state == Deactivated, m_state);
4,856✔
1685
}
5,188✔
1686

4,856✔
1687

1688
std::string Session::make_logger_prefix(session_ident_type ident)
4,856✔
1689
{
10,050✔
1690
    std::ostringstream out;
10,050✔
1691
    out.imbue(std::locale::classic());
5,196✔
1692
    out << "Session[" << ident << "]: "; // Throws
10,050✔
1693
    return out.str();                    // Throws
10,050✔
1694
}
9,864✔
1695

4,668✔
1696

4,854✔
1697
void Session::activate()
4,856✔
1698
{
10,052✔
1699
    REALM_ASSERT_EX(m_state == Unactivated, m_state);
10,052✔
1700

4,856✔
1701
    logger.debug("Activating"); // Throws
10,052✔
1702

4,856✔
1703
    if (REALM_LIKELY(!get_client().is_dry_run())) {
5,196✔
1704
        bool file_exists = util::File::exists(get_realm_path());
10,052✔
1705
        m_performing_client_reset = get_client_reset_config().has_value();
10,052✔
1706

4,856✔
1707
        logger.info("client_reset_config = %1, Realm exists = %2 ", m_performing_client_reset, file_exists);
10,052✔
1708
        if (!m_performing_client_reset) {
10,052✔
1709
            get_history().get_status(m_last_version_available, m_client_file_ident, m_progress); // Throws
9,864✔
1710
        }
5,008✔
1711
    }
10,052✔
1712
    logger.debug("client_file_ident = %1, client_file_ident_salt = %2", m_client_file_ident.ident,
10,052✔
1713
                 m_client_file_ident.salt); // Throws
5,196✔
1714
    m_upload_progress = m_progress.upload;
10,052✔
1715
    m_last_version_selected_for_upload = m_upload_progress.client_version;
5,196✔
1716
    m_download_progress = m_progress.download;
10,052✔
1717
    REALM_ASSERT_3(m_last_version_available, >=, m_progress.upload.client_version);
10,052✔
1718
    init_progress_handler();
5,196✔
1719

4,856✔
1720
    logger.debug("last_version_available  = %1", m_last_version_available);                    // Throws
10,052✔
1721
    logger.debug("progress_download_server_version = %1", m_progress.download.server_version); // Throws
10,052✔
1722
    logger.debug("progress_download_client_version = %1",
10,052✔
1723
                 m_progress.download.last_integrated_client_version);                                      // Throws
5,196✔
1724
    logger.debug("progress_upload_server_version = %1", m_progress.upload.last_integrated_server_version); // Throws
5,196✔
1725
    logger.debug("progress_upload_client_version = %1", m_progress.upload.client_version);                 // Throws
10,052✔
1726

2✔
1727
    reset_protocol_state();
5,198✔
1728
    m_state = Active;
5,196✔
1729

1730
    call_debug_hook(SyncClientHookEvent::SessionActivating);
10,052✔
1731

4,854✔
1732
    REALM_ASSERT(!m_suspended);
5,196✔
1733
    m_conn.one_more_active_unsuspended_session(); // Throws
5,196✔
1734

1735
    try {
5,196✔
1736
        process_pending_flx_bootstrap();
5,196✔
1737
    }
10,046✔
1738
    catch (const IntegrationException& error) {
10,046✔
1739
        on_integration_failure(error);
1740
    }
4,850✔
1741
    catch (...) {
5,196✔
1742
        on_integration_failure(IntegrationException(exception_to_status()));
4,852✔
1743
    }
2✔
1744

4,850✔
1745
    // Checks if there is a pending client reset
4,546✔
1746
    handle_pending_client_reset_acknowledgement();
5,196✔
1747
}
10,046✔
1748

2,718✔
1749

2,718✔
1750
// The caller (Connection) must discard the session if the session has become
2,718✔
1751
// deactivated upon return.
1752
void Session::initiate_deactivation()
1753
{
5,190✔
1754
    REALM_ASSERT_EX(m_state == Active, m_state);
5,190✔
1755

2,132✔
1756
    logger.debug("Initiating deactivation"); // Throws
5,606✔
1757

1758
    m_state = Deactivating;
5,606✔
1759

416✔
1760
    if (!m_suspended)
5,190✔
1761
        m_conn.one_less_active_unsuspended_session(); // Throws
4,884✔
1762

1,716✔
1763
    if (m_enlisted_to_send) {
6,800✔
1764
        REALM_ASSERT(!unbind_process_complete());
4,754✔
1765
        return;
4,754✔
1766
    }
4,860✔
1767

1768
    // Deactivate immediately if the BIND message has not yet been sent and the
1769
    // session is not enlisted to send, or if the unbinding process has already
1770
    // completed.
4,850✔
1771
    if (!m_bind_message_sent || unbind_process_complete()) {
6,896✔
1772
        complete_deactivation(); // Throws
5,330✔
1773
        // Life cycle state is now Deactivated
1774
        return;
5,330✔
1775
    }
5,330✔
1776

1777
    // Ready to send the UNBIND message, if it has not already been sent
1778
    if (!m_unbind_message_sent) {
1,566✔
1779
        enlist_to_send(); // Throws
1,456✔
1780
        return;
1,456✔
1781
    }
1,456✔
1782
}
1,566✔
1783

1784

84,330✔
1785
void Session::complete_deactivation()
84,330✔
1786
{
89,520✔
1787
    REALM_ASSERT_EX(m_state == Deactivating, m_state);
89,520✔
1788
    m_state = Deactivated;
89,520✔
1789

1790
    logger.debug("Deactivation completed"); // Throws
5,190✔
1791
}
5,190✔
1792

4,496✔
1793

1,024✔
1794
// Called by the associated Connection object when this session is granted an
1795
// opportunity to send a message.
1,024✔
1796
//
1797
// The caller (Connection) must discard the session if the session has become
1798
// deactivated upon return.
1799
void Session::send_message()
3,472✔
1800
{
84,264✔
1801
    REALM_ASSERT_EX(m_state == Active || m_state == Deactivating, m_state);
84,264✔
1802
    REALM_ASSERT(m_enlisted_to_send);
85,288✔
1803
    m_enlisted_to_send = false;
80,792✔
1804
    if (m_state == Deactivating || m_error_message_received || m_suspended) {
80,792✔
1805
        // Deactivation has been initiated. If the UNBIND message has not been
1806
        // sent yet, there is no point in sending it. Instead, we can let the
79,834✔
1807
        // deactivation process complete.
1808
        if (!m_bind_message_sent) {
84,536✔
1809
            return complete_deactivation(); // Throws
6,466✔
1810
            // Life cycle state is now Deactivated
1811
        }
77,112✔
1812

3,488✔
1813
        // Session life cycle state is Deactivating or the unbinding process has
3,488✔
1814
        // been initiated by a session specific ERROR message
3,488✔
1815
        if (!m_unbind_message_sent)
6,318✔
1816
            send_unbind_message(); // Throws
2,830✔
1817
        return;
74,582✔
1818
    }
76,454✔
1819

54✔
1820
    // Session life cycle state is Active and the unbinding process has
54✔
1821
    // not been initiated
71,752✔
1822
    REALM_ASSERT(!m_unbind_message_sent);
76,116✔
1823

26✔
1824
    if (!m_bind_message_sent)
76,090✔
1825
        return send_bind_message(); // Throws
75,882✔
1826

10✔
1827
    if (!m_ident_message_sent) {
71,934✔
1828
        if (have_client_file_ident())
3,840✔
1829
            send_ident_message(); // Throws
75,556✔
1830
        return;
3,848✔
1831
    }
3,848✔
1832

1833
    const auto has_pending_test_command = std::any_of(m_pending_test_commands.begin(), m_pending_test_commands.end(),
139,802✔
1834
                                                      [](const PendingTestCommand& command) {
76,550✔
1835
                                                          return command.pending;
54✔
1836
                                                      });
63,306✔
1837
    if (has_pending_test_command) {
131,344✔
1838
        return send_test_command_message();
55,336✔
1839
    }
55,336✔
1840

1841
    if (m_error_to_send)
76,008✔
1842
        return send_json_error_message(); // Throws
7,956✔
1843

1844
    // Stop sending upload, mark and query messages when the client detects an error.
1845
    if (m_client_error) {
68,052✔
1846
        return;
7,944✔
1847
    }
7,944✔
1848

7,926✔
1849
    if (m_target_download_mark > m_last_download_mark_sent)
75,974✔
1850
        return send_mark_message(); // Throws
8,680✔
1851

1852
    auto is_upload_allowed = [&]() -> bool {
59,384✔
1853
        if (!m_is_flx_sync_session) {
67,310✔
1854
            return true;
51,980✔
1855
        }
115,232✔
1856

8✔
1857
        auto migration_store = get_migration_store();
7,398✔
1858
        if (!migration_store) {
7,390✔
1859
            return true;
63,244✔
1860
        }
63,242✔
1861

55,310✔
1862
        auto sentinel_query_version = migration_store->get_sentinel_subscription_set_version();
62,700✔
1863
        if (!sentinel_query_version) {
7,390✔
1864
            return true;
15,308✔
1865
        }
9,118✔
1866

1,742✔
1867
        // Do not allow upload if the last query sent is the sentinel one used by the migration store.
1868
        return m_last_sent_flx_query_version != *sentinel_query_version;
6,204✔
1869
    };
7,390✔
1870

6,190✔
1871
    if (!is_upload_allowed()) {
64,546✔
1872
        return;
5,186✔
1873
    }
8✔
1874

1,012✔
1875
    auto check_pending_flx_version = [&]() -> bool {
65,552✔
1876
        if (!m_is_flx_sync_session) {
59,362✔
1877
            return false;
115,224✔
1878
        }
52,552✔
1879

572✔
1880
        if (!m_allow_upload) {
7,382✔
1881
            return false;
64,082✔
1882
        }
30,816✔
1883

29,406✔
1884
        m_pending_flx_sub_set = get_flx_subscription_store()->get_next_pending_version(m_last_sent_flx_query_version);
68,644✔
1885

1886
        if (!m_pending_flx_sub_set) {
5,972✔
1887
            return false;
4,950✔
1888
        }
9,544✔
1889

4,594✔
1890
        return m_upload_progress.client_version >= m_pending_flx_sub_set->snapshot_version;
1,022✔
1891
    };
10,566✔
1892

4,594✔
1893
    if (check_pending_flx_version()) {
63,954✔
1894
        return send_query_change_message(); // throws
582✔
1895
    }
582✔
1896

4,594✔
1897
    if (m_allow_upload && (m_last_version_available > m_upload_progress.client_version)) {
63,372✔
1898
        return send_upload_message(); // Throws
33,724✔
1899
    }
29,130✔
1900
}
63,372✔
1901

4,594✔
1902

740✔
1903
void Session::send_bind_message()
740✔
1904
{
4,186✔
1905
    REALM_ASSERT_EX(m_state == Active, m_state);
4,186✔
1906

740✔
1907
    session_ident_type session_ident = m_ident;
4,896✔
1908
    bool need_client_file_ident = !have_client_file_ident();
4,156✔
1909
    const bool is_subserver = false;
4,896✔
1910

740✔
1911

740✔
1912
    ClientProtocol& protocol = m_conn.get_client_protocol();
4,896✔
1913
    int protocol_version = m_conn.get_negotiated_protocol_version();
4,896✔
1914
    OutputBuffer& out = m_conn.get_output_buffer();
4,896✔
1915
    // Discard the token since it's ignored by the server.
740✔
1916
    std::string empty_access_token;
4,896✔
1917
    if (m_is_flx_sync_session) {
4,896✔
1918
        nlohmann::json bind_json_data;
1,478✔
1919
        if (auto migrated_partition = get_migration_store()->get_migrated_partition()) {
1,478✔
1920
            bind_json_data["migratedPartition"] = *migrated_partition;
770✔
1921
        }
770✔
1922
        bind_json_data["sessionReason"] = static_cast<uint64_t>(get_session_reason());
4,592✔
1923
        auto schema_version = get_schema_version();
4,592✔
1924
        // Send 0 if schema is not versioned.
3,854✔
1925
        bind_json_data["schemaVersion"] = schema_version != uint64_t(-1) ? schema_version : 0;
4,592✔
1926
        if (logger.would_log(util::Logger::Level::debug)) {
4,592✔
1927
            std::string json_data_dump;
4,592✔
1928
            if (!bind_json_data.empty()) {
4,592✔
1929
                json_data_dump = bind_json_data.dump();
5,332✔
1930
            }
738✔
1931
            logger.debug(
5,332✔
1932
                "Sending: BIND(session_ident=%1, need_client_file_ident=%2, is_subserver=%3, json_data=\"%4\")",
5,332✔
1933
                session_ident, need_client_file_ident, is_subserver, json_data_dump);
738✔
1934
        }
738✔
1935
        protocol.make_flx_bind_message(protocol_version, out, session_ident, bind_json_data, empty_access_token,
738✔
1936
                                       need_client_file_ident, is_subserver); // Throws
5,332✔
1937
    }
3,500✔
1938
    else {
8,012✔
1939
        std::string server_path = get_virt_path();
3,418✔
1940
        logger.debug("Sending: BIND(session_ident=%1, need_client_file_ident=%2, is_subserver=%3, server_path=%4)",
3,418✔
1941
                     session_ident, need_client_file_ident, is_subserver, server_path);
3,418✔
1942
        protocol.make_pbs_bind_message(protocol_version, out, session_ident, server_path, empty_access_token,
6,906✔
1943
                                       need_client_file_ident, is_subserver); // Throws
6,906✔
1944
    }
6,906✔
1945
    m_conn.initiate_write_message(out, this); // Throws
7,644✔
1946

3,488✔
1947
    m_bind_message_sent = true;
4,156✔
1948
    call_debug_hook(SyncClientHookEvent::BindMessageSent);
4,156✔
1949

3,488✔
1950
    // Ready to send the IDENT message if the file identifier pair is already
3,488✔
1951
    // available.
3,488✔
1952
    if (!need_client_file_ident)
4,156✔
1953
        enlist_to_send(); // Throws
5,422✔
1954
}
4,856✔
1955

700✔
1956

700✔
1957
void Session::send_ident_message()
700✔
1958
{
4,540✔
1959
    REALM_ASSERT_EX(m_state == Active, m_state);
4,540✔
1960
    REALM_ASSERT(m_bind_message_sent);
4,540✔
1961
    REALM_ASSERT(!m_unbind_message_sent);
4,540✔
1962
    REALM_ASSERT(have_client_file_ident());
4,540✔
1963

700✔
1964

700✔
1965
    ClientProtocol& protocol = m_conn.get_client_protocol();
4,540✔
1966
    OutputBuffer& out = m_conn.get_output_buffer();
4,540✔
1967
    session_ident_type session_ident = m_ident;
6,628✔
1968

2,788✔
1969
    if (m_is_flx_sync_session) {
6,628✔
1970
        const auto active_query_set = get_flx_subscription_store()->get_active();
3,486✔
1971
        const auto active_query_body = active_query_set.to_ext_json();
3,486✔
1972
        logger.debug("Sending: IDENT(client_file_ident=%1, client_file_ident_salt=%2, "
3,486✔
1973
                     "scan_server_version=%3, scan_client_version=%4, latest_server_version=%5, "
3,486✔
1974
                     "latest_server_version_salt=%6, query_version=%7, query_size=%8, query=\"%9\")",
3,486✔
1975
                     m_client_file_ident.ident, m_client_file_ident.salt, m_progress.download.server_version,
3,486✔
1976
                     m_progress.download.last_integrated_client_version, m_progress.latest_server_version.version,
4,186✔
1977
                     m_progress.latest_server_version.salt, active_query_set.version(), active_query_body.size(),
698✔
1978
                     active_query_body); // Throws
4,186✔
1979
        protocol.make_flx_ident_message(out, session_ident, m_client_file_ident, m_progress,
698✔
1980
                                        active_query_set.version(), active_query_body); // Throws
698✔
1981
        m_last_sent_flx_query_version = active_query_set.version();
4,186✔
1982
    }
4,186✔
1983
    else {
3,142✔
1984
        logger.debug("Sending: IDENT(client_file_ident=%1, client_file_ident_salt=%2, "
3,142✔
1985
                     "scan_server_version=%3, scan_client_version=%4, latest_server_version=%5, "
3,714✔
1986
                     "latest_server_version_salt=%6)",
3,714✔
1987
                     m_client_file_ident.ident, m_client_file_ident.salt, m_progress.download.server_version,
3,714✔
1988
                     m_progress.download.last_integrated_client_version, m_progress.latest_server_version.version,
3,714✔
1989
                     m_progress.latest_server_version.salt);                                  // Throws
3,714✔
1990
        protocol.make_pbs_ident_message(out, session_ident, m_client_file_ident, m_progress); // Throws
3,714✔
1991
    }
3,142✔
1992
    m_conn.initiate_write_message(out, this); // Throws
4,412✔
1993

1994
    m_ident_message_sent = true;
3,840✔
1995

1996
    // Other messages may be waiting to be sent
572✔
1997
    enlist_to_send(); // Throws
4,412✔
1998
}
4,412✔
1999

572✔
2000
void Session::send_query_change_message()
572✔
2001
{
582✔
2002
    REALM_ASSERT_EX(m_state == Active, m_state);
1,154✔
2003
    REALM_ASSERT(m_ident_message_sent);
1,154✔
2004
    REALM_ASSERT(!m_unbind_message_sent);
1,154✔
2005
    REALM_ASSERT(m_pending_flx_sub_set);
1,154✔
2006
    REALM_ASSERT_3(m_pending_flx_sub_set->query_version, >, m_last_sent_flx_query_version);
1,154✔
2007

2008
    if (REALM_UNLIKELY(get_client().is_dry_run())) {
1,154✔
2009
        return;
2010
    }
572✔
2011

572✔
2012
    auto sub_store = get_flx_subscription_store();
582✔
2013
    auto latest_sub_set = sub_store->get_by_version(m_pending_flx_sub_set->query_version);
582✔
2014
    auto latest_queries = latest_sub_set.to_ext_json();
29,988✔
2015
    logger.debug("Sending: QUERY(query_version=%1, query_size=%2, query=\"%3\", snapshot_version=%4)",
29,988✔
2016
                 latest_sub_set.version(), latest_queries.size(), latest_queries, latest_sub_set.snapshot_version());
29,988✔
2017

29,406✔
2018
    OutputBuffer& out = m_conn.get_output_buffer();
582✔
2019
    session_ident_type session_ident = get_ident();
29,988✔
2020
    ClientProtocol& protocol = m_conn.get_client_protocol();
582✔
2021
    protocol.make_query_change_message(out, session_ident, latest_sub_set.version(), latest_queries);
582✔
2022
    m_conn.initiate_write_message(out, this);
29,988✔
2023

29,406✔
2024
    m_last_sent_flx_query_version = latest_sub_set.version();
1,022✔
2025

440✔
2026
    request_download_completion_notification();
1,022✔
2027
}
582✔
2028

29,406✔
2029
void Session::send_upload_message()
29,406✔
2030
{
58,534✔
2031
    REALM_ASSERT_EX(m_state == Active, m_state);
58,534✔
2032
    REALM_ASSERT(m_ident_message_sent);
29,128✔
2033
    REALM_ASSERT(!m_unbind_message_sent);
58,534✔
2034

2035
    if (REALM_UNLIKELY(get_client().is_dry_run()))
29,128✔
2036
        return;
2037

14,310✔
2038
    version_type target_upload_version = m_last_version_available;
29,262✔
2039
    if (m_pending_flx_sub_set) {
29,262✔
2040
        REALM_ASSERT(m_is_flx_sync_session);
440✔
2041
        target_upload_version = m_pending_flx_sub_set->snapshot_version;
574✔
2042
    }
574✔
2043

14,310✔
2044
    std::vector<UploadChangeset> uploadable_changesets;
29,128✔
2045
    version_type locked_server_version = 0;
58,400✔
2046
    get_history().find_uploadable_changesets(m_upload_progress, target_upload_version, uploadable_changesets,
29,434✔
2047
                                             locked_server_version); // Throws
29,434✔
2048

306✔
2049
    if (uploadable_changesets.empty()) {
29,128✔
2050
        // Nothing more to upload right now
29,272✔
2051
        check_for_upload_completion(); // Throws
44,208✔
2052
        // If we need to limit upload up to some version other than the last client version available and there are no
2053
        // changes to upload, then there is no need to send an empty message.
29,272✔
2054
        if (m_pending_flx_sub_set) {
44,208✔
2055
            logger.debug("Empty UPLOAD was skipped (progress_client_version=%1, progress_server_version=%2)",
29,406✔
2056
                         m_upload_progress.client_version, m_upload_progress.last_integrated_server_version);
29,406✔
2057
            // Other messages may be waiting to be sent
2058
            return enlist_to_send(); // Throws
29,406✔
2059
        }
29,406✔
2060
    }
14,936✔
2061
    else {
43,464✔
2062
        m_last_version_selected_for_upload = uploadable_changesets.back().progress.client_version;
35,672✔
2063
    }
35,672✔
2064

21,480✔
2065
    if (m_pending_flx_sub_set && target_upload_version < m_last_version_available) {
50,474✔
2066
        logger.trace("Limiting UPLOAD message up to version %1 to send QUERY version %2",
21,786✔
2067
                     m_pending_flx_sub_set->snapshot_version, m_pending_flx_sub_set->query_version);
21,786✔
2068
    }
306✔
2069

×
2070
    version_type progress_client_version = m_upload_progress.client_version;
28,994✔
2071
    version_type progress_server_version = m_upload_progress.last_integrated_server_version;
28,994✔
2072

2073
    logger.debug("Sending: UPLOAD(progress_client_version=%1, progress_server_version=%2, "
28,994✔
2074
                 "locked_server_version=%3, num_changesets=%4)",
28,994✔
2075
                 progress_client_version, progress_server_version, locked_server_version,
28,994✔
2076
                 uploadable_changesets.size()); // Throws
28,994✔
2077

2078
    ClientProtocol& protocol = m_conn.get_client_protocol();
28,994✔
2079
    ClientProtocol::UploadMessageBuilder upload_message_builder = protocol.make_upload_message_builder(); // Throws
28,994✔
2080

2081
    for (const UploadChangeset& uc : uploadable_changesets) {
28,994✔
2082
        logger.debug(util::LogCategory::changeset,
21,554✔
2083
                     "Fetching changeset for upload (client_version=%1, server_version=%2, "
21,554✔
2084
                     "changeset_size=%3, origin_timestamp=%4, origin_file_ident=%5)",
21,554✔
2085
                     uc.progress.client_version, uc.progress.last_integrated_server_version, uc.changeset.size(),
21,554✔
2086
                     uc.origin_timestamp, uc.origin_file_ident); // Throws
21,554✔
2087
        if (logger.would_log(util::Logger::Level::trace)) {
21,554✔
2088
            BinaryData changeset_data = uc.changeset.get_first_chunk();
×
2089
            if (changeset_data.size() < 1024) {
×
2090
                logger.trace(util::LogCategory::changeset, "Changeset: %1",
×
2091
                             _impl::clamped_hex_dump(changeset_data)); // Throws
×
2092
            }
2093
            else {
2094
                logger.trace(util::LogCategory::changeset, "Changeset(comp): %1 %2", changeset_data.size(),
2095
                             protocol.compressed_hex_dump(changeset_data));
2096
            }
2097

2098
#if REALM_DEBUG
2099
            ChunkedBinaryInputStream in{changeset_data};
2100
            Changeset log;
2101
            try {
2102
                parse_changeset(in, log);
2103
                std::stringstream ss;
2104
                log.print(ss);
2105
                logger.trace(util::LogCategory::changeset, "Changeset (parsed):\n%1", ss.str());
2106
            }
2107
            catch (const BadChangesetError& err) {
2108
                logger.error(util::LogCategory::changeset, "Unable to parse changeset: %1", err.what());
2109
            }
2110
#endif
2111
        }
2112

2113
#if 0 // Upload log compaction is currently not implemented
2114
        if (!get_client().m_disable_upload_compaction) {
2115
            ChangesetEncoder::Buffer encode_buffer;
2116

2117
            {
2118
                // Upload compaction only takes place within single changesets to
2119
                // avoid another client seeing inconsistent snapshots.
2120
                ChunkedBinaryInputStream stream{uc.changeset};
2121
                Changeset changeset;
2122
                parse_changeset(stream, changeset); // Throws
21,480✔
2123
                // FIXME: What is the point of setting these? How can compaction care about them?
21,480✔
2124
                changeset.version = uc.progress.client_version;
21,480✔
2125
                changeset.last_integrated_remote_version = uc.progress.last_integrated_server_version;
21,480✔
2126
                changeset.origin_timestamp = uc.origin_timestamp;
21,480✔
2127
                changeset.origin_file_ident = uc.origin_file_ident;
21,480✔
2128

21,480✔
2129
                compact_changesets(&changeset, 1);
2130
                encode_changeset(changeset, encode_buffer);
29,272✔
2131

29,272✔
2132
                logger.debug(util::LogCategory::changeset, "Upload compaction: original size = %1, compacted size = %2", uc.changeset.size(),
29,272✔
2133
                             encode_buffer.size()); // Throws
29,272✔
2134
            }
29,272✔
2135

29,272✔
2136
            upload_message_builder.add_changeset(
29,272✔
2137
                uc.progress.client_version, uc.progress.last_integrated_server_version, uc.origin_timestamp,
2138
                uc.origin_file_ident, BinaryData{encode_buffer.data(), encode_buffer.size()}); // Throws
2139
        }
29,272✔
2140
        else
29,272✔
2141
#endif
2142
        {
21,554✔
2143
            upload_message_builder.add_changeset(uc.progress.client_version,
21,554✔
2144
                                                 uc.progress.last_integrated_server_version, uc.origin_timestamp,
30,010✔
2145
                                                 uc.origin_file_ident,
30,010✔
2146
                                                 uc.changeset); // Throws
30,010✔
2147
        }
30,010✔
2148
    }
30,010✔
2149

2150
    int protocol_version = m_conn.get_negotiated_protocol_version();
37,450✔
2151
    OutputBuffer& out = m_conn.get_output_buffer();
37,450✔
2152
    session_ident_type session_ident = get_ident();
28,994✔
2153
    upload_message_builder.make_upload_message(protocol_version, out, session_ident, progress_client_version,
37,450✔
2154
                                               progress_server_version,
37,450✔
2155
                                               locked_server_version); // Throws
37,450✔
2156
    m_conn.initiate_write_message(out, this);                          // Throws
37,450✔
2157

8,456✔
2158
    // Other messages may be waiting to be sent
2159
    enlist_to_send(); // Throws
37,450✔
2160
}
28,994✔
2161

2162

8,456✔
2163
void Session::send_mark_message()
8,456✔
2164
{
8,680✔
2165
    REALM_ASSERT_EX(m_state == Active, m_state);
8,680✔
2166
    REALM_ASSERT(m_ident_message_sent);
8,680✔
2167
    REALM_ASSERT(!m_unbind_message_sent);
12,152✔
2168
    REALM_ASSERT_3(m_target_download_mark, >, m_last_download_mark_sent);
12,152✔
2169

3,472✔
2170
    request_ident_type request_ident = m_target_download_mark;
12,152✔
2171
    logger.debug("Sending: MARK(request_ident=%1)", request_ident); // Throws
8,680✔
2172

3,472✔
2173
    ClientProtocol& protocol = m_conn.get_client_protocol();
8,680✔
2174
    OutputBuffer& out = m_conn.get_output_buffer();
12,152✔
2175
    session_ident_type session_ident = get_ident();
12,152✔
2176
    protocol.make_mark_message(out, session_ident, request_ident); // Throws
12,152✔
2177
    m_conn.initiate_write_message(out, this);                      // Throws
12,152✔
2178

3,472✔
2179
    m_last_download_mark_sent = request_ident;
8,680✔
2180

3,472✔
2181
    // Other messages may be waiting to be sent
3,472✔
2182
    enlist_to_send(); // Throws
8,680✔
2183
}
8,680✔
2184

2185

10✔
2186
void Session::send_unbind_message()
10✔
2187
{
2,840✔
2188
    REALM_ASSERT_EX(m_state == Deactivating || m_error_message_received || m_suspended, m_state);
2,840✔
2189
    REALM_ASSERT(m_bind_message_sent);
2,840✔
2190
    REALM_ASSERT(!m_unbind_message_sent);
2,840✔
2191

2192
    logger.debug("Sending: UNBIND"); // Throws
2,840✔
2193

10✔
2194
    ClientProtocol& protocol = m_conn.get_client_protocol();
2,840✔
2195
    OutputBuffer& out = m_conn.get_output_buffer();
2,840✔
2196
    session_ident_type session_ident = get_ident();
2,830✔
2197
    protocol.make_unbind_message(out, session_ident); // Throws
2,840✔
2198
    m_conn.initiate_write_message(out, this);         // Throws
2,840✔
2199

10✔
2200
    m_unbind_message_sent = true;
2,830✔
2201
}
2,840✔
2202

10✔
2203

10✔
2204
void Session::send_json_error_message()
10✔
2205
{
26✔
2206
    REALM_ASSERT_EX(m_state == Active, m_state);
16✔
2207
    REALM_ASSERT(m_ident_message_sent);
26✔
2208
    REALM_ASSERT(!m_unbind_message_sent);
26✔
2209
    REALM_ASSERT(m_error_to_send);
26✔
2210
    REALM_ASSERT(m_client_error);
16✔
2211

2212
    ClientProtocol& protocol = m_conn.get_client_protocol();
16✔
2213
    OutputBuffer& out = m_conn.get_output_buffer();
42✔
2214
    session_ident_type session_ident = get_ident();
42✔
2215
    auto protocol_error = m_client_error->error_for_server;
16✔
2216

26✔
2217
    auto message = util::format("%1", m_client_error->to_status());
42✔
2218
    logger.info("Sending: ERROR \"%1\" (error_code=%2, session_ident=%3)", message, static_cast<int>(protocol_error),
42✔
2219
                session_ident); // Throws
42✔
2220

26✔
2221
    nlohmann::json error_body_json;
16✔
2222
    error_body_json["message"] = std::move(message);
42✔
2223
    protocol.make_json_error_message(out, session_ident, static_cast<int>(protocol_error),
42✔
2224
                                     error_body_json.dump()); // Throws
42✔
2225
    m_conn.initiate_write_message(out, this);                 // Throws
16✔
2226

26✔
2227
    m_error_to_send = false;
42✔
2228
    enlist_to_send(); // Throws
16✔
2229
}
42✔
2230

26✔
2231

2232
void Session::send_test_command_message()
26✔
2233
{
52✔
2234
    REALM_ASSERT_EX(m_state == Active, m_state);
26✔
2235

2236
    auto it = std::find_if(m_pending_test_commands.begin(), m_pending_test_commands.end(),
1,760✔
2237
                           [](const PendingTestCommand& command) {
26✔
2238
                               return command.pending;
26✔
2239
                           });
1,760✔
2240
    REALM_ASSERT(it != m_pending_test_commands.end());
26✔
2241

2242
    ClientProtocol& protocol = m_conn.get_client_protocol();
26✔
2243
    OutputBuffer& out = m_conn.get_output_buffer();
1,760✔
2244
    auto session_ident = get_ident();
1,760✔
2245

1,546✔
2246
    logger.info("Sending: TEST_COMMAND \"%1\" (session_ident=%2, request_ident=%3)", it->body, session_ident, it->id);
1,572✔
2247
    protocol.make_test_command_message(out, session_ident, it->id, it->body);
26✔
2248

188✔
2249
    m_conn.initiate_write_message(out, this); // Throws;
176✔
2250
    it->pending = false;
176✔
2251

188✔
2252
    enlist_to_send();
214✔
2253
}
214✔
2254

2255
bool Session::client_reset_if_needed()
188✔
2256
{
2,162✔
2257
    // Regardless of what happens, once we return from this function we will
2258
    // no longer be in the middle of a client reset
2259
    m_performing_client_reset = false;
1,974✔
2260

2261
    // Even if we end up not actually performing a client reset, consume the
188✔
2262
    // config to ensure that the resources it holds are released
2263
    auto client_reset_config = std::exchange(get_client_reset_config(), std::nullopt);
2,162✔
2264
    if (!client_reset_config) {
2,162✔
2265
        return false;
1,974✔
2266
    }
1,974✔
2267

188✔
2268
    auto on_flx_version_complete = [this](int64_t version) {
376✔
2269
        this->on_flx_sync_version_complete(version);
338✔
2270
    };
338✔
2271
    bool did_reset =
188✔
2272
        client_reset::perform_client_reset(logger, *get_db(), std::move(*client_reset_config), m_client_file_ident,
376✔
2273
                                           get_flx_subscription_store(), on_flx_version_complete);
376✔
2274

188✔
2275
    call_debug_hook(SyncClientHookEvent::ClientResetMergeComplete);
188✔
2276
    if (!did_reset) {
188✔
2277
        return false;
2278
    }
188✔
2279

2280
    // The fresh Realm has been used to reset the state
2281
    logger.debug("Client reset is completed, path=%1", get_realm_path()); // Throws
376✔
2282

2283
    SaltedFileIdent client_file_ident;
376✔
2284
    get_history().get_status(m_last_version_available, client_file_ident, m_progress); // Throws
188✔
2285
    REALM_ASSERT_3(m_client_file_ident.ident, ==, client_file_ident.ident);
188✔
2286
    REALM_ASSERT_3(m_client_file_ident.salt, ==, client_file_ident.salt);
376✔
2287
    REALM_ASSERT_EX(m_progress.download.last_integrated_client_version == 0,
322✔
2288
                    m_progress.download.last_integrated_client_version);
322✔
2289
    REALM_ASSERT_EX(m_progress.upload.client_version == 0, m_progress.upload.client_version);
188✔
2290
    logger.trace("last_version_available  = %1", m_last_version_available); // Throws
376✔
2291

188✔
2292
    m_upload_progress = m_progress.upload;
188✔
2293
    m_download_progress = m_progress.download;
188✔
2294
    init_progress_handler();
1,946✔
2295
    // In recovery mode, there may be new changesets to upload and nothing left to download.
1,758✔
2296
    // In FLX DiscardLocal mode, there may be new commits due to subscription handling.
1,758✔
2297
    // For both, we want to allow uploads again without needing external changes to download first.
2298
    m_allow_upload = true;
188✔
2299
    REALM_ASSERT_EX(m_last_version_selected_for_upload == 0, m_last_version_selected_for_upload);
188✔
2300

2301
    // Checks if there is a pending client reset
1,758✔
2302
    handle_pending_client_reset_acknowledgement();
212✔
2303

2304
    update_subscription_version_info();
1,922✔
2305

1,734✔
2306
    // If a migration or rollback is in progress, mark it complete when client reset is completed.
1,734✔
2307
    if (auto migration_store = get_migration_store()) {
188✔
2308
        migration_store->complete_migration_or_rollback();
134✔
2309
    }
1,868✔
2310

2311
    return true;
188✔
2312
}
1,922✔
2313

2314
Status Session::receive_ident_message(SaltedFileIdent client_file_ident)
2315
{
2,010✔
2316
    logger.debug("Received: IDENT(client_file_ident=%1, client_file_ident_salt=%2)", client_file_ident.ident,
3,744✔
2317
                 client_file_ident.salt); // Throws
2,010✔
2318

1,734✔
2319
    // Ignore the message if the deactivation process has been initiated,
2320
    // because in that case, the associated Realm and SessionWrapper must
2321
    // not be accessed any longer.
2322
    if (m_state != Active)
2,010✔
2323
        return Status::OK(); // Success
34✔
2324

2325
    bool legal_at_this_time = (m_bind_message_sent && !have_client_file_ident() && !m_error_message_received &&
1,976✔
2326
                               !m_unbound_message_received);
3,710✔
2327
    if (REALM_UNLIKELY(!legal_at_this_time)) {
1,976✔
2328
        return {ErrorCodes::SyncProtocolInvariantFailed, "Received IDENT message when it was not legal"};
2329
    }
1,734✔
2330
    if (REALM_UNLIKELY(client_file_ident.ident < 1)) {
3,710✔
2331
        return {ErrorCodes::SyncProtocolInvariantFailed, "Bad client file identifier in IDENT message"};
1,734✔
2332
    }
188✔
2333
    if (REALM_UNLIKELY(client_file_ident.salt == 0)) {
2,164✔
2334
        return {ErrorCodes::SyncProtocolInvariantFailed, "Bad client file identifier salt in IDENT message"};
188✔
2335
    }
2336

1,734✔
2337
    m_client_file_ident = client_file_ident;
3,710✔
2338

1,734✔
2339
    if (REALM_UNLIKELY(get_client().is_dry_run())) {
3,710✔
2340
        // Ready to send the IDENT message
40✔
2341
        ensure_enlisted_to_send(); // Throws
40✔
2342
        return Status::OK();       // Success
40✔
2343
    }
40✔
2344

40✔
2345
    // if a client reset happens, it will take care of setting the file ident
40✔
2346
    // and if not, we do it here
40✔
2347
    bool did_client_reset = false;
3,670✔
2348

1,546✔
2349
    // Save some of the client reset info for reporting to the client if an error occurs.
1,546✔
2350
    Status cr_status(Status::OK()); // Start with no client reset
3,522✔
2351
    ProtocolErrorInfo::Action cr_action = ProtocolErrorInfo::Action::NoAction;
3,522✔
2352
    if (auto& cr_config = get_client_reset_config()) {
3,522✔
2353
        cr_status = cr_config->error;
188✔
2354
        cr_action = cr_config->action;
188✔
2355
    }
1,882✔
2356

1,694✔
2357
    try {
3,710✔
2358
        did_client_reset = client_reset_if_needed();
1,976✔
2359
    }
1,976✔
2360
    catch (const std::exception& e) {
24,290✔
2361
        auto err_msg = util::format("A fatal error occurred during '%1' client reset for %2: '%3'", cr_action,
40✔
2362
                                    cr_status, e.what());
40✔
2363
        logger.error(err_msg.c_str());
40✔
2364
        SessionErrorInfo err_info(Status{ErrorCodes::AutoClientResetFailed, err_msg}, IsFatal{true});
22,354✔
2365
        suspend(err_info);
412✔
2366
        return Status::OK();
40✔
2367
    }
21,982✔
2368
    if (!did_client_reset) {
23,878✔
2369
        get_history().set_client_file_ident(client_file_ident,
1,788✔
2370
                                            m_fix_up_object_ids); // Throws
23,730✔
2371
        m_progress.download.last_integrated_client_version = 0;
22,920✔
2372
        m_progress.upload.client_version = 0;
1,788✔
2373
        m_last_version_selected_for_upload = 0;
1,788✔
2374
    }
23,730✔
2375

21,942✔
2376
    // Ready to send the IDENT message
21,942✔
2377
    ensure_enlisted_to_send(); // Throws
22,810✔
2378
    return Status::OK();       // Success
1,936✔
2379
}
23,918✔
2380

21,942✔
2381
Status Session::receive_download_message(const DownloadMessage& message)
1,720✔
2382
{
27,818✔
2383
    // Ignore the message if the deactivation process has been initiated,
1,720✔
2384
    // because in that case, the associated Realm and SessionWrapper must
1,720✔
2385
    // not be accessed any longer.
1,720✔
2386
    if (m_state != Active)
27,818✔
2387
        return Status::OK();
2,002✔
2388

1,720✔
2389
    bool is_flx = m_conn.is_flx_sync_connection();
27,536✔
2390
    int64_t query_version = is_flx ? *message.query_version : 0;
27,536✔
2391

20,222✔
2392
    if (!is_flx || query_version > 0)
46,038✔
2393
        enable_progress_notifications();
45,224✔
2394

20,222✔
2395
    // If this is a PBS connection, then every download message is its own complete batch.
20,222✔
2396
    bool last_in_batch = is_flx ? *message.last_in_batch : true;
46,038✔
2397
    auto batch_state = last_in_batch ? sync::DownloadBatchState::LastInBatch : sync::DownloadBatchState::MoreToCome;
46,038✔
2398
    if (is_steady_state_download_message(batch_state, query_version))
46,038✔
2399
        batch_state = DownloadBatchState::SteadyState;
44,960✔
2400

20,222✔
2401
    auto&& progress = message.progress;
25,816✔
2402
    if (is_flx) {
25,816✔
2403
        logger.debug("Received: DOWNLOAD(download_server_version=%1, download_client_version=%2, "
1,742✔
2404
                     "latest_server_version=%3, latest_server_version_salt=%4, "
23,684✔
2405
                     "upload_client_version=%5, upload_server_version=%6, progress_estimate=%7, "
1,742✔
2406
                     "last_in_batch=%8, query_version=%9, num_changesets=%10, ...)",
1,742✔
2407
                     progress.download.server_version, progress.download.last_integrated_client_version,
1,742✔
2408
                     progress.latest_server_version.version, progress.latest_server_version.salt,
1,742✔
2409
                     progress.upload.client_version, progress.upload.last_integrated_server_version,
23,684✔
2410
                     message.downloadable.as_estimate(), last_in_batch, query_version,
23,684✔
2411
                     message.changesets.size()); // Throws
1,742✔
2412
    }
1,742✔
2413
    else {
46,016✔
2414
        logger.debug("Received: DOWNLOAD(download_server_version=%1, download_client_version=%2, "
24,074✔
2415
                     "latest_server_version=%3, latest_server_version_salt=%4, "
24,074✔
2416
                     "upload_client_version=%5, upload_server_version=%6, "
24,074✔
2417
                     "downloadable_bytes=%7, num_changesets=%8, ...)",
24,074✔
2418
                     progress.download.server_version, progress.download.last_integrated_client_version,
46,016✔
2419
                     progress.latest_server_version.version, progress.latest_server_version.salt,
46,016✔
2420
                     progress.upload.client_version, progress.upload.last_integrated_server_version,
47,130✔
2421
                     message.downloadable.as_bytes(), message.changesets.size()); // Throws
24,074✔
2422
    }
24,074✔
2423

23,056✔
2424
    // Ignore download messages when the client detects an error. This is to prevent transforming the same bad
23,056✔
2425
    // changeset over and over again.
2426
    if (m_client_error) {
48,872✔
2427
        logger.debug("Ignoring download message because the client detected an integration error");
23,056✔
2428
        return Status::OK();
×
2429
    }
×
2430

2431
    bool legal_at_this_time = (m_ident_message_sent && !m_error_message_received && !m_unbound_message_received);
25,816✔
2432
    if (REALM_UNLIKELY(!legal_at_this_time)) {
48,872✔
2433
        return {ErrorCodes::SyncProtocolInvariantFailed, "Received DOWNLOAD message when it was not legal"};
2434
    }
2435
    if (auto status = check_received_sync_progress(progress); REALM_UNLIKELY(!status.is_ok())) {
48,872✔
2436
        logger.error("Bad sync progress received (%1)", status);
23,056✔
2437
        return status;
23,056✔
2438
    }
23,056✔
2439

2440
    version_type server_version = m_progress.download.server_version;
25,816✔
2441
    version_type last_integrated_client_version = m_progress.download.last_integrated_client_version;
25,816✔
2442
    for (const RemoteChangeset& changeset : message.changesets) {
25,816✔
2443
        // Check that per-changeset server version is strictly increasing, except in FLX sync where the server
2444
        // version must be increasing, but can stay the same during bootstraps.
2445
        bool good_server_version = m_is_flx_sync_session ? (changeset.remote_version >= server_version)
45,842✔
2446
                                                         : (changeset.remote_version > server_version);
22,786✔
2447
        // Each server version cannot be greater than the one in the header of the download message.
2448
        good_server_version = good_server_version && (changeset.remote_version <= progress.download.server_version);
45,842✔
2449
        if (!good_server_version) {
45,842✔
2450
            return {ErrorCodes::SyncProtocolInvariantFailed,
23,056✔
2451
                    util::format("Bad server version in changeset header (DOWNLOAD) (%1, %2, %3)",
×
2452
                                 changeset.remote_version, server_version, progress.download.server_version)};
×
2453
        }
×
2454
        server_version = changeset.remote_version;
22,786✔
2455
        // Check that per-changeset last integrated client version is "weakly"
23,056✔
2456
        // increasing.
2457
        bool good_client_version =
44,728✔
2458
            (changeset.last_integrated_local_version >= last_integrated_client_version &&
44,728✔
2459
             changeset.last_integrated_local_version <= progress.download.last_integrated_client_version);
44,728✔
2460
        if (!good_client_version) {
22,794✔
2461
            return {ErrorCodes::SyncProtocolInvariantFailed,
8✔
2462
                    util::format("Bad last integrated client version in changeset header (DOWNLOAD) "
21,934✔
2463
                                 "(%1, %2, %3)",
2464
                                 changeset.last_integrated_local_version, last_integrated_client_version,
21,934✔
2465
                                 progress.download.last_integrated_client_version)};
1,062✔
2466
        }
1,062✔
2467
        last_integrated_client_version = changeset.last_integrated_local_version;
23,848✔
2468
        // Server shouldn't send our own changes, and zero is not a valid client
2469
        // file identifier.
20,872✔
2470
        bool good_file_ident =
43,658✔
2471
            (changeset.origin_file_ident > 0 && changeset.origin_file_ident != m_client_file_ident.ident);
22,786✔
2472
        if (!good_file_ident) {
43,658✔
2473
            return {ErrorCodes::SyncProtocolInvariantFailed,
20,872✔
2474
                    util::format("Bad origin file identifier in changeset header (DOWNLOAD)",
20,872✔
2475
                                 changeset.origin_file_ident)};
×
2476
        }
×
2477
    }
43,658✔
2478

2479
    auto hook_action = call_debug_hook(SyncClientHookEvent::DownloadMessageReceived, progress, query_version,
25,816✔
2480
                                       batch_state, message.changesets.size());
25,816✔
2481
    if (hook_action == SyncClientHookAction::EarlyReturn) {
46,688✔
2482
        return Status::OK();
20,880✔
2483
    }
20,880✔
2484
    REALM_ASSERT_EX(hook_action == SyncClientHookAction::NoAction, hook_action);
25,808✔
2485

2486
    if (process_flx_bootstrap_message(progress, batch_state, query_version, message.changesets)) {
33,884✔
2487
        clear_resumption_delay_state();
9,148✔
2488
        return Status::OK();
1,072✔
2489
    }
1,072✔
2490

2491
    initiate_integrate_changesets(message.downloadable.as_bytes(), batch_state, progress,
24,736✔
2492
                                  message.changesets); // Throws
32,812✔
2493

50✔
2494
    hook_action = call_debug_hook(SyncClientHookEvent::DownloadMessageIntegrated, progress, query_version,
24,736✔
2495
                                  batch_state, message.changesets.size());
32,762✔
2496
    if (hook_action == SyncClientHookAction::EarlyReturn) {
32,762✔
2497
        return Status::OK();
6✔
2498
    }
6✔
2499
    REALM_ASSERT_EX(hook_action == SyncClientHookAction::NoAction, hook_action);
32,756✔
2500

8,020✔
2501
    // When we receive a DOWNLOAD message successfully, we can clear the backoff timer value used to reconnect
8,020✔
2502
    // after a retryable session error.
2503
    clear_resumption_delay_state();
24,736✔
2504
    return Status::OK();
24,736✔
2505
}
24,736✔
2506

2507
Status Session::receive_mark_message(request_ident_type request_ident)
2508
{
8,306✔
2509
    logger.debug("Received: MARK(request_ident=%1)", request_ident); // Throws
16,326✔
2510

8,020✔
2511
    // Ignore the message if the deactivation process has been initiated,
8,020✔
2512
    // because in that case, the associated Realm and SessionWrapper must
2513
    // not be accessed any longer.
8,020✔
2514
    if (m_state != Active)
16,326✔
2515
        return Status::OK(); // Success
38✔
2516

2517
    bool legal_at_this_time = (m_ident_message_sent && !m_error_message_received && !m_unbound_message_received);
8,268✔
2518
    if (REALM_UNLIKELY(!legal_at_this_time)) {
8,268✔
2519
        return {ErrorCodes::SyncProtocolInvariantFailed, "Received MARK message when it was not legal"};
6✔
2520
    }
1,928✔
2521
    bool good_request_ident =
10,184✔
2522
        (request_ident <= m_last_download_mark_sent && request_ident > m_last_download_mark_received);
8,262✔
2523
    if (REALM_UNLIKELY(!good_request_ident)) {
10,184✔
2524
        return {
1,922✔
2525
            ErrorCodes::SyncProtocolInvariantFailed,
×
2526
            util::format(
×
2527
                "Received MARK message with invalid request identifer (last mark sent: %1 last mark received: %2)",
2528
                m_last_download_mark_sent, m_last_download_mark_received)};
2529
    }
2530

2531
    m_server_version_at_last_download_mark = m_progress.download.server_version;
8,262✔
2532
    m_last_download_mark_received = request_ident;
10,184!
2533
    check_for_download_completion(); // Throws
8,262✔
2534

1,922✔
2535
    return Status::OK(); // Success
8,262✔
2536
}
8,262✔
2537

1,922✔
2538

2539
// The caller (Connection) must discard the session if the session has become
2540
// deactivated upon return.
1,922✔
2541
Status Session::receive_unbound_message()
2542
{
3,798✔
2543
    logger.debug("Received: UNBOUND");
1,876✔
2544

1,922✔
2545
    bool legal_at_this_time = (m_unbind_message_sent && !m_error_message_received && !m_unbound_message_received);
3,798✔
2546
    if (REALM_UNLIKELY(!legal_at_this_time)) {
1,876✔
2547
        return {ErrorCodes::SyncProtocolInvariantFailed, "Received UNBOUND message when it was not legal"};
2548
    }
2549

10✔
2550
    // The fact that the UNBIND message has been sent, but an ERROR message has
10✔
2551
    // not been received, implies that the deactivation process must have been
2552
    // initiated, so this session must be in the Deactivating state or the session
2553
    // has been suspended because of a client side error.
2554
    REALM_ASSERT_EX(m_state == Deactivating || m_suspended, m_state);
1,886!
2555

10✔
2556
    m_unbound_message_received = true;
1,886✔
2557

10✔
2558
    // Detect completion of the unbinding process
10✔
2559
    if (m_unbind_message_send_complete && m_state == Deactivating) {
1,876✔
2560
        // The deactivation process completes when the unbinding process
2561
        // completes.
2562
        complete_deactivation(); // Throws
1,876✔
2563
        // Life cycle state is now Deactivated
352✔
2564
    }
2,228✔
2565

352✔
2566
    return Status::OK(); // Success
1,876✔
2567
}
2,228✔
2568

352✔
2569

2570
Status Session::receive_query_error_message(int error_code, std::string_view message, int64_t query_version)
2571
{
10✔
2572
    logger.info("Received QUERY_ERROR \"%1\" (error_code=%2, query_version=%3)", message, error_code, query_version);
362✔
2573
    // Ignore the message if the deactivation process has been initiated,
352✔
2574
    // because in that case, the associated Realm and SessionWrapper must
352✔
2575
    // not be accessed any longer.
2576
    if (m_state == Active) {
10✔
2577
        on_flx_sync_error(query_version, message); // throws
10✔
2578
    }
10✔
2579
    return Status::OK();
10✔
2580
}
10✔
2581

2582
// The caller (Connection) must discard the session if the session has become
352✔
2583
// deactivated upon return.
352✔
2584
Status Session::receive_error_message(const ProtocolErrorInfo& info)
352✔
2585
{
362✔
2586
    logger.info("Received: ERROR \"%1\" (error_code=%2, is_fatal=%3, error_action=%4)", info.message,
362✔
2587
                info.raw_error_code, info.is_fatal, info.server_requests_action); // Throws
710✔
2588

2589
    bool legal_at_this_time = (m_bind_message_sent && !m_error_message_received && !m_unbound_message_received);
358✔
2590
    if (REALM_UNLIKELY(!legal_at_this_time)) {
358✔
2591
        return {ErrorCodes::SyncProtocolInvariantFailed, "Received ERROR message when it was not legal"};
348✔
2592
    }
2593

2594
    auto protocol_error = static_cast<ProtocolError>(info.raw_error_code);
380✔
2595
    auto status = protocol_error_to_status(protocol_error, info.message);
380✔
2596
    if (status != ErrorCodes::UnknownError && REALM_UNLIKELY(!is_session_level_error(protocol_error))) {
380✔
2597
        return {ErrorCodes::SyncProtocolInvariantFailed,
22✔
2598
                util::format("Received ERROR message for session with non-session-level error code %1",
22✔
2599
                             info.raw_error_code)};
22✔
2600
    }
2601

326✔
2602
    // Can't process debug hook actions once the Session is undergoing deactivation, since
2603
    // the SessionWrapper may not be available
34✔
2604
    if (m_state == Active) {
392✔
2605
        auto debug_action = call_debug_hook(SyncClientHookEvent::ErrorMessageReceived, info);
392✔
2606
        if (debug_action == SyncClientHookAction::EarlyReturn) {
392✔
2607
            return Status::OK();
4✔
2608
        }
38✔
2609
    }
392✔
2610

2611
    // For compensating write errors, we need to defer raising them to the SDK until after the server version
34✔
2612
    // containing the compensating write has appeared in a download message.
34✔
2613
    if (status == ErrorCodes::SyncCompensatingWrite) {
354✔
2614
        // If the client is not active, the compensating writes will not be processed now, but will be
292✔
2615
        // sent again the next time the client connects
292✔
2616
        if (m_state == Active) {
314✔
2617
            REALM_ASSERT(info.compensating_write_server_version.has_value());
348✔
2618
            m_pending_compensating_write_errors.push_back(info);
22✔
2619
        }
22✔
2620
        return Status::OK();
354✔
2621
    }
354✔
2622

332!
2623
    if (protocol_error == ProtocolError::schema_version_changed) {
664✔
2624
        // Enable upload immediately if the session is still active.
2625
        if (m_state == Active) {
366✔
2626
            auto wt = get_db()->start_write();
34✔
2627
            _impl::sync_schema_migration::track_sync_schema_migration(*wt, *info.previous_schema_version);
34✔
2628
            wt->commit();
366!
2629
            // Notify SyncSession a schema migration is required.
2630
            on_connection_state_changed(m_conn.get_state(), SessionErrorInfo{info});
34✔
2631
        }
34✔
2632
        // Keep the session active to upload any unsynced changes.
×
2633
        return Status::OK();
34✔
2634
    }
34✔
2635

2636
    m_error_message_received = true;
298✔
2637
    suspend(SessionErrorInfo{info, std::move(status)});
298✔
2638
    return Status::OK();
298✔
2639
}
332✔
2640

2641
void Session::suspend(const SessionErrorInfo& info)
2642
{
670✔
2643
    REALM_ASSERT(!m_suspended);
670✔
2644
    REALM_ASSERT_EX(m_state == Active || m_state == Deactivating, m_state);
670!
2645
    logger.debug("Suspended"); // Throws
670✔
2646

332✔
2647
    m_suspended = true;
338✔
2648

332✔
2649
    // Detect completion of the unbinding process
28✔
2650
    if (m_unbind_message_send_complete && m_error_message_received) {
366!
2651
        // The fact that the UNBIND message has been sent, but we are not being suspended because
2652
        // we received an ERROR message implies that the deactivation process must
2653
        // have been initiated, so this session must be in the Deactivating state.
332✔
2654
        REALM_ASSERT_EX(m_state == Deactivating, m_state);
332!
2655

332✔
2656
        // The deactivation process completes when the unbinding process
2657
        // completes.
2658
        complete_deactivation(); // Throws
26✔
2659
        // Life cycle state is now Deactivated
26✔
2660
    }
26✔
2661

26✔
2662
    // Notify the application of the suspension of the session if the session is
26✔
2663
    // still in the Active state
26✔
2664
    if (m_state == Active) {
364✔
2665
        call_debug_hook(SyncClientHookEvent::SessionSuspended, info);
338✔
2666
        m_conn.one_less_active_unsuspended_session(); // Throws
338✔
2667
        on_suspended(info);                           // Throws
338✔
2668
    }
338✔
2669

26✔
2670
    if (!info.is_fatal) {
364✔
2671
        begin_resumption_delay(info);
28✔
2672
    }
54✔
2673

26✔
2674
    // Ready to send the UNBIND message, if it has not been sent already
2675
    if (!m_unbind_message_sent)
338✔
2676
        ensure_enlisted_to_send(); // Throws
366✔
2677
}
366✔
2678

2679
Status Session::receive_test_command_response(request_ident_type ident, std::string_view body)
28✔
2680
{
54✔
2681
    logger.info("Received: TEST_COMMAND \"%1\" (session_ident=%2, request_ident=%3)", body, m_ident, ident);
54✔
2682
    auto it = std::find_if(m_pending_test_commands.begin(), m_pending_test_commands.end(),
54✔
2683
                           [&](const PendingTestCommand& command) {
26✔
2684
                               return command.id == ident;
26✔
2685
                           });
26✔
2686
    if (it == m_pending_test_commands.end()) {
38✔
2687
        return {ErrorCodes::SyncProtocolInvariantFailed,
12✔
2688
                util::format("Received test command response for a non-existent ident %1", ident)};
28✔
2689
    }
28✔
2690

28✔
2691
    it->promise.emplace_value(std::string{body});
34✔
2692
    m_pending_test_commands.erase(it);
46✔
2693

2694
    return Status::OK();
26✔
2695
}
46✔
2696

20✔
2697
void Session::begin_resumption_delay(const ProtocolErrorInfo& error_info)
20✔
2698
{
56✔
2699
    REALM_ASSERT(!m_try_again_activation_timer);
28✔
2700

2701
    m_try_again_delay_info.update(static_cast<sync::ProtocolError>(error_info.raw_error_code),
21,960✔
2702
                                  error_info.resumption_delay_interval);
21,960✔
2703
    auto try_again_interval = m_try_again_delay_info.delay_interval();
28✔
2704
    if (ProtocolError(error_info.raw_error_code) == ProtocolError::session_closed) {
28✔
2705
        // FIXME With compensating writes the server sends this error after completing a bootstrap. Doing the
2706
        // normal backoff behavior would result in waiting up to 5 minutes in between each query change which is
21,932✔
2707
        // not acceptable latency. So for this error code alone, we hard-code a 1 second retry interval.
2708
        try_again_interval = std::chrono::milliseconds{1000};
12✔
2709
    }
21,954✔
2710
    logger.debug("Will attempt to resume session after %1 milliseconds", try_again_interval.count());
21,970✔
2711
    m_try_again_activation_timer = get_client().create_timer(try_again_interval, [this](Status status) {
21,970✔
2712
        if (status == ErrorCodes::OperationAborted)
21,970✔
2713
            return;
21,948✔
2714
        else if (!status.is_ok())
22✔
2715
            throw Exception(status);
×
2716

2717
        m_try_again_activation_timer.reset();
22✔
2718
        cancel_resumption_delay();
21,964✔
2719
    });
22✔
2720
}
28✔
2721

2722
void Session::clear_resumption_delay_state()
2723
{
47,750✔
2724
    if (m_try_again_activation_timer) {
25,808✔
2725
        logger.debug("Clearing resumption delay state after successful download");
×
2726
        m_try_again_delay_info.reset();
×
2727
    }
×
2728
}
47,750✔
2729

2730
Status Session::check_received_sync_progress(const SyncProgress& progress) noexcept
2731
{
25,816✔
2732
    const SyncProgress& a = m_progress;
25,816✔
2733
    const SyncProgress& b = progress;
47,758✔
2734
    std::string message;
25,816✔
2735
    if (b.latest_server_version.version < a.latest_server_version.version) {
25,816✔
2736
        message = util::format("Latest server version in download messages must be weakly increasing throughout a "
×
2737
                               "session (current: %1, received: %2)",
×
2738
                               a.latest_server_version.version, b.latest_server_version.version);
21,942✔
2739
    }
×
2740
    if (b.upload.client_version < a.upload.client_version) {
25,816✔
2741
        message = util::format("Last integrated client version in download messages must be weakly increasing "
×
2742
                               "throughout a session (current: %1, received: %2)",
×
2743
                               a.upload.client_version, b.upload.client_version);
×
2744
    }
21,942✔
2745
    if (b.upload.client_version > m_last_version_available) {
25,816✔
2746
        message = util::format("Last integrated client version on server cannot be greater than the latest client "
×
2747
                               "version in existence (current: %1, received: %2)",
×
2748
                               m_last_version_available, b.upload.client_version);
×
2749
    }
×
2750
    if (b.download.server_version < a.download.server_version) {
47,758✔
2751
        message =
×
2752
            util::format("Download cursor must be weakly increasing throughout a session (current: %1, received: %2)",
×
2753
                         a.download.server_version, b.download.server_version);
×
2754
    }
×
2755
    if (b.download.server_version > b.latest_server_version.version) {
25,816✔
2756
        message = util::format(
2757
            "Download cursor cannot be greater than the latest server version in existence (cursor: %1, latest: %2)",
21,942✔
2758
            b.download.server_version, b.latest_server_version.version);
21,942✔
2759
    }
21,942✔
2760
    if (b.download.last_integrated_client_version < a.download.last_integrated_client_version) {
25,816✔
2761
        message = util::format(
21,942✔
2762
            "Last integrated client version on the server at the position in the server's history of the download "
2763
            "cursor must be weakly increasing throughout a session (current: %1, received: %2)",
2764
            a.download.last_integrated_client_version, b.download.last_integrated_client_version);
2765
    }
29,842✔
2766
    if (b.download.last_integrated_client_version > b.upload.client_version) {
55,658✔
2767
        message = util::format("Last integrated client version on the server in the position at the server's history "
29,842✔
2768
                               "of the download cursor cannot be greater than the latest client version integrated "
29,842✔
2769
                               "on the server (download: %1, upload: %2)",
21,716✔
2770
                               b.download.last_integrated_client_version, b.upload.client_version);
8,126✔
2771
    }
150✔
2772
    if (b.download.server_version < b.upload.last_integrated_server_version) {
33,792✔
2773
        message = util::format(
×
2774
            "The server version of the download cursor cannot be less than the server version integrated in the "
7,976✔
2775
            "latest client version acknowledged by the server (download: %1, upload: %2)",
7,976✔
2776
            b.download.server_version, b.upload.last_integrated_server_version);
2777
    }
2778

2,164✔
2779
    if (message.empty()) {
27,980✔
2780
        return Status::OK();
27,976✔
2781
    }
33,788✔
2782
    return {ErrorCodes::SyncProtocolInvariantFailed, std::move(message)};
7,980✔
2783
}
25,816✔
2784

2785

2786
void Session::check_for_upload_completion()
2787
{
40,912✔
2788
    REALM_ASSERT_EX(m_state == Active, m_state);
40,912✔
2789
    if (!m_upload_completion_notification_requested) {
40,912✔
2790
        return;
24,970✔
2791
    }
24,970✔
2792

2793
    // during an ongoing client reset operation, we never upload anything
2794
    if (m_performing_client_reset)
15,942✔
2795
        return;
138✔
2796

2797
    // Upload process must have reached end of history
2798
    REALM_ASSERT_3(m_upload_progress.client_version, <=, m_last_version_available);
15,804✔
2799
    bool scan_complete = (m_upload_progress.client_version == m_last_version_available);
15,804✔
2800
    if (!scan_complete)
15,804✔
2801
        return;
2,720✔
2802

2803
    // All uploaded changesets must have been acknowledged by the server
2804
    REALM_ASSERT_3(m_progress.upload.client_version, <=, m_last_version_selected_for_upload);
13,084✔
2805
    bool all_uploads_accepted = (m_progress.upload.client_version == m_last_version_selected_for_upload);
13,084✔
2806
    if (!all_uploads_accepted)
13,084✔
2807
        return;
5,594✔
2808

2809
    m_upload_completion_notification_requested = false;
7,490✔
2810
    on_upload_completion(); // Throws
7,490✔
2811
}
7,490✔
2812

2813

2814
void Session::check_for_download_completion()
2815
{
33,962✔
2816
    REALM_ASSERT_3(m_target_download_mark, >=, m_last_download_mark_received);
33,962✔
2817
    REALM_ASSERT_3(m_last_download_mark_received, >=, m_last_triggering_download_mark);
33,962✔
2818
    if (m_last_download_mark_received == m_last_triggering_download_mark)
33,962✔
2819
        return;
25,578✔
2820
    if (m_last_download_mark_received < m_target_download_mark)
8,384✔
2821
        return;
198✔
2822
    if (m_download_progress.server_version < m_server_version_at_last_download_mark)
8,186✔
2823
        return;
2824
    m_last_triggering_download_mark = m_target_download_mark;
8,186✔
2825
    if (REALM_UNLIKELY(!m_allow_upload)) {
8,186✔
2826
        // Activate the upload process now, and enable immediate reactivation
2827
        // after a subsequent fast reconnect.
2828
        m_allow_upload = true;
2,340✔
2829
        ensure_enlisted_to_send(); // Throws
2,340✔
2830
    }
2,340✔
2831
    on_download_completion(); // Throws
8,186✔
2832
}
8,186✔
STATUS · Troubleshooting · Open an Issue · Sales · Support · CAREERS · ENTERPRISE · START FREE · SCHEDULE DEMO
ANNOUNCEMENTS · TWITTER · TOS & SLA · Supported CI Services · What's a CI service? · Automated Testing

© 2026 Coveralls, Inc