Details
Major Description
Summary:
When using the Flutter plugin (based on CBLite C 3.1.0), when disconnecting from the internet, replication is not resumed once reconnecting.
Steps to reproduce:
1. Clone this repo: https://github.com/couchbaselabs/flutter_cblite_userprofile_sync
2. Follow steps in repo to deploy flutter app + app services
3. Login and update information
4. Updated user info will sync to CB
5. Disconnect emulator from web (Wifi, Cellular and Airplane mode all cause the same issue)
6. Update user profile and click save
7. Reconnect emulator to internet.
8. The updated user info will NOT sync
9. You can get the sync to work by signing out, relogging in and saving again.
Trace log (debug level):
I/flutter ( 4156): 18:48:42.707813| [DB] verbose: mbedTLS(C): => read
I/flutter ( 4156): 18:48:42.711167| [DB] verbose: mbedTLS(C): => read record
I/flutter ( 4156): 18:48:42.715554| [DB] verbose: mbedTLS(C): => fetch input
I/flutter ( 4156): 18:48:42.719194| [DB] verbose: mbedTLS(C): in_left: 0, nb_want: 5
I/flutter ( 4156): 18:48:42.719617| [DB] verbose: mbedTLS(C): SockPP: >>> BIO Error code 103 results in a transfer error
I/flutter ( 4156): 18:48:42.719848| [DB] verbose: mbedTLS(C): in_left: 0, nb_want: 5
I/flutter ( 4156): 18:48:42.720202| [DB] verbose: mbedTLS(C): ssl->f_recv(_timeout)() returned -76 (-0x004c)
I/flutter ( 4156): 18:48:42.720348| [DB] error: mbedTLS(C): mbedtls_ssl_fetch_input() returned -76 (-0x004c)
I/flutter ( 4156): 18:48:42.720575| [DB] error: mbedTLS(C): ssl_get_next_record() returned -76 (-0x004c)
I/flutter ( 4156): 18:48:42.720741| [DB] error: mbedTLS(C): mbedtls_ssl_read_record() returned -76 (-0x004c)
I/flutter ( 4156): 18:48:42.720983| [WS] warning: ClientSocket got POSIX error 5 "I/O error"
I/flutter ( 4156): 18:48:42.724245| [WS] verbose: {N8litecore9websocket16BuiltInWebSocketE#9} Calling onClose before calling closeSocket/requestClose
I/flutter ( 4156): 18:48:42.724721| [WS] error: {N8litecore9websocket16BuiltInWebSocketE#9} Unexpected or unclean socket disconnect! (reason=errno 5)
I/flutter ( 4156): 18:48:42.725695| [WS] info: {N8litecore9websocket16BuiltInWebSocketE#9} sent 1435 bytes, rcvd 560, in 35.118 sec (41/sec, 16/sec)
I/flutter ( 4156): 18:48:42.726508| [DB] verbose: mbedTLS(C): => write close notify
I/flutter ( 4156): 18:48:42.726856| [DB] verbose: mbedTLS(C): => send alert message
I/flutter ( 4156): 18:48:42.727569| [DB] verbose: mbedTLS(C): send alert level=1 message=0
I/flutter ( 4156): 18:48:42.728083| [DB] verbose: mbedTLS(C): => write record
I/flutter ( 4156): 18:48:42.728574| [DB] verbose: mbedTLS(C): => encrypt buf
I/flutter ( 4156): 18:48:42.729326| [DB] debug: mbedTLS(C): dumping 'before encrypt: output payload' (2 bytes)
I/flutter ( 4156): 18:48:42.729751| [DB] debug: mbedTLS(C): 0000: 01 00 ..
I/flutter ( 4156): 18:48:42.730428| [DB] debug: mbedTLS(C): dumping 'IV used (internal)' (12 bytes)
I/flutter ( 4156): 18:48:42.730670| [DB] debug: mbedTLS(C): 0000: bb f6 21 5f 00 00 00 00 00 00 00 11 ..!_........
I/flutter ( 4156): 18:48:42.731643| [DB] debug: mbedTLS(C): dumping 'IV used (transmitted)' (8 bytes)
I/flutter ( 4156): 18:48:42.732167| [DB] debug: mbedTLS(C): 0000: 00 00 00 00 00 00 00 11 ........
I/flutter ( 4156): 18:48:42.732985| [DB] debug: mbedTLS(C): dumping 'additional data used for AEAD' (13 bytes)
I/flutter ( 4156): 18:48:42.733235| [DB] debug: mbedTLS(C): 0000: 00 00 00 00 00 00 00 11 15 03 03 00 02 .............
I/flutter ( 4156): 18:48:42.733992| [DB] verbose: mbedTLS(C): before encrypt: msglen = 2, including 0 bytes of padding
I/flutter ( 4156): 18:48:42.734309| [DB] debug: mbedTLS(C): dumping 'after encrypt: tag' (16 bytes)
I/flutter ( 4156): 18:48:42.734609| [DB] debug: mbedTLS(C): 0000: 31 a9 b0 5b 6c 5c 32 ae ad f9 e3 25 75 30 3d 78 1..[l\2....%u0=x
I/flutter ( 4156): 18:48:42.735196| [DB] verbose: mbedTLS(C): <= encrypt buf
I/flutter ( 4156): 18:48:42.735630| [DB] verbose: mbedTLS(C): output record: msgtype = 21, version = [3:3], msglen = 26
I/flutter ( 4156): 18:48:42.735968| [DB] debug: mbedTLS(C): dumping 'output record sent to network' (31 bytes)
I/flutter ( 4156): 18:48:42.736659| [DB] debug: mbedTLS(C): 0000: 15 03 03 00 1a 00 00 00 00 00 00 00 11 be 61 31 ..............a1
I/flutter ( 4156): 18:48:42.737057| [DB] debug: mbedTLS(C): 0010: a9 b0 5b 6c 5c 32 ae ad f9 e3 25 75 30 3d 78 ..[l\2....%u0=x
I/flutter ( 4156): 18:48:42.737276| [DB] verbose: mbedTLS(C): => flush output
I/flutter ( 4156): 18:48:42.737460| [DB] verbose: mbedTLS(C): message length: 31, out_left: 31
I/flutter ( 4156): 18:48:42.737631| [DB] verbose: mbedTLS(C): ssl->f_send() returned -80 (-0x0050)
I/flutter ( 4156): 18:48:42.738164| [DB] error: mbedTLS(C): mbedtls_ssl_flush_output() returned -80 (-0x0050)
I/flutter ( 4156): 18:48:42.739041| [DB] error: mbedTLS(C): mbedtls_ssl_write_record() returned -80 (-0x0050)
I/flutter ( 4156): 18:48:42.751856| [DB] error: mbedTLS(C): mbedtls_ssl_send_alert_message() returned -80 (-0x0050)
I/flutter ( 4156): 18:48:42.754153| [DB] verbose: mbedTLS(C): => free
I/flutter ( 4156): 18:48:42.754429| [DB] verbose: mbedTLS(C): <= free
I/flutter ( 4156): 18:48:42.755881| [Sync] info: {Repl#7} {Coll#-1} Connection closed with errno 5: "I/O error" (state=2)
I/flutter ( 4156): 18:48:42.763986| [Sync] info: {N8litecore4repl6PusherE#15} {Coll#0} activityLevel=stopped: pendingResponseCount=0, caughtUp=1, changeLists=0, revsInFlight=0, blobsInFlight=0, awaitingReply=0, revsToSend=0, pushingDocs=0, pendingSequences=0
I/flutter ( 4156): 18:48:42.766165| [Sync] verbose: {N8litecore4repl6PusherE#15} {Coll#0} now stopped
I/flutter ( 4156): 18:48:42.766803| [Sync] error: {Repl#7} Got LiteCore error: POSIX error 5, "I/O error"
I/flutter ( 4156): 18:48:42.767321| [Sync] verbose: {Repl#7} {Coll#-1} (collection: 4294967295) progress +0/+0, 0 docs – now 110 / 110, 2 docs
I/flutter ( 4156): 18:48:42.767727| [Sync] info: {Repl#7} {Coll#-1} activityLevel=busy: connectionState=-1, savingChkpt=0
I/flutter ( 4156): 18:48:42.767902| [Sync] info: {Repl#7} {Coll#-1} now busy
I/flutter ( 4156): 18:48:42.768619| [Sync] error: {C4Replicator#8} State: busy, progress=100.00%, error=POSIX error 5, "I/O error"
I/flutter ( 4156): 18:48:42.768837| [Sync] info: {Repl#7} {Coll#-1} pushStatus=stopped, pullStatus=idle, progress=110/110/2
I/flutter ( 4156): 18:48:42.769028| [Sync] verbose: {Repl#7} {Coll#-1} Replicator status collection-wise: pushStatus=stopped, pullStatus=idle, progress=110/110, docCount=2
I/flutter ( 4156): 18:48:42.769409| [Sync] info: {Repl#7} {Coll#-1} activityLevel=stopped: connectionState=-1, savingChkpt=0
I/flutter ( 4156): 18:48:42.769757| [Sync] info: {Repl#7} {Coll#-1} now stopped
I/flutter ( 4156): 18:48:42.771155| [DB] verbose: {DB#20} Housekeeping: 0 of 19 pages free (0%)
I/flutter ( 4156): 18:48:42.771956| [DB] verbose: {DB#20} Closed SQLite database
I/flutter ( 4156): 18:48:42.772441| [DB] info: {DB#20} Closing database
I/flutter ( 4156): 18:48:42.772822| [DB] info: {N8litecore14CollectionImplE#21} Closed
I/flutter ( 4156): 18:48:42.773106| [Sync] error: {C4Replicator#8} State: stopped, progress=100.00%, error=POSIX error 5, "I/O error"
I/flutter ( 4156): 18:48:42.773416| [Sync] info: CBLReplicator status: stopped, progress=110/110, flag=2, error=2/5 (effective status=stopped, completed=1.00%, docs=2)
I/flutter ( 4156): 18:48:42.773888| [DB] info: {N8litecore24CollectionChangeNotifierE#17} Deleting
I/flutter ( 4156): 18:48:42.773996| [DB] verbose: {N8litecore15SequenceTrackerE#23} Removed 0 old entries (1 left; idle has 0, byDocID has 1)
I/flutter ( 4156): 18:48:42.774178| [DB] verbose: {DB#5} Housekeeping: 0 of 19 pages free (0%)
I/flutter ( 4156): 18:48:42.774538| [DB] verbose: {DB#5} Closed SQLite database
I/flutter ( 4156): 18:48:42.775040| [DB] info: {DB#5} Closing database
I/flutter ( 4156): 18:48:42.775180| [DB] info: {N8litecore14CollectionImplE#6} Closed
I/flutter ( 4156): 18:48:42.775764| [Sync] info: {N8litecore4repl6PullerE#18} {Coll#0} activityLevel=stopped: pendingResponseCount=0, _caughtUp=1, _pendingRevMessages=0, _activeIncomingRevs=0, _waitingRevMessages=0, _unfinishedIncomingRevs=0
I/flutter ( 4156): 18:48:42.776401| [Sync] verbose: {N8litecore4repl6PullerE#18} {Coll#0} now stopped
I/flutter ( 4156): 18:48:42.776899| [Sync] info: BLIP sent 15 msgs (1339 bytes), rcvd 3 msgs (532 bytes) in 35.168 sec. Max outbox depth was 1, avg 1.00
CC: Marco Bevilacqua