Skip to content

Instantly share code, notes, and snippets.

@hideki
Created March 20, 2015 00:20
Show Gist options
  • Save hideki/d0c5ebe01f8880131f66 to your computer and use it in GitHub Desktop.
Save hideki/d0c5ebe01f8880131f66 to your computer and use it in GitHub Desktop.
testGoOffline() failure Log
3-19 20:14:27.769 1329-1360/? D/Batcher﹕ com.couchbase.lite.support.Batcher@b1e87fd0: /waitForPendingFutures
03-19 20:14:27.769 1329-1360/? W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:14:27.769 1329-1360/? E/Sync﹕ PullerInternal stopGraceful.run() finished
03-19 20:14:27.779 1329-1347/? D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:14:27.779 1329-1347/? I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:14:27.779 1329-1347/? V/Sync﹕ [onExit()] IDLE => IDLE
03-19 20:14:27.779 1329-1347/? V/Sync﹕ [onEntry()] IDLE => IDLE
03-19 20:14:32.759 1329-1347/? D/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1ef1828: saveLastSequence() called. lastSequence: 2 remoteCheckpoint: null
03-19 20:14:32.759 1329-1347/? I/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1ef1828: start put remote _local document. checkpointID: 1103cab91f0be83bb51e2671b97324671205d0c3 body: {lastSequence=2}
03-19 20:14:32.789 1329-1347/? D/dalvikvm﹕ GC_FOR_ALLOC freed 443K, 16% free 3954K/4680K, paused 27ms, total 31ms
03-19 20:14:32.799 1329-1347/? D/Sync﹕ [sendAsyncRequest()] PUT => http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.799 1329-1347/? V/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry@b1ecd188: RemoteRequestRetry created, url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.799 1329-1347/? V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ee6490: RemoteRequest created, url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.809 1329-1368/? V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ee6490: RemoteRequest run() called, url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.809 1329-1347/? W/Sync﹕ [fireTrigger()] => RESUME
03-19 20:14:32.809 1329-1347/? D/Sync﹕ firing trigger: RESUME
03-19 20:14:32.809 1329-1347/? I/StateMachine﹕ Firing RESUME
03-19 20:14:32.809 1329-1347/? V/Sync﹕ [onExit()] IDLE => RUNNING
03-19 20:14:32.809 1329-1347/? D/Sync﹕ State transition: IDLE -> RUNNING (via RESUME). this: com.couchbase.lite.replicator.PullerInternal@b1ef1828
03-19 20:14:32.809 1329-1374/? D/Sync﹕ calling future.get() on com.couchbase.lite.support.RemoteRequestRetry@b1ecd188
03-19 20:14:32.809 1329-1368/? V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ee6490: RemoteRequest calling httpClient.execute, url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.809 1329-1368/? V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ee6490: RemoteRequest calling httpClient.execute, client: org.apache.http.impl.client.DefaultHttpClient@b1f1e320 url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.869 1329-1372/? I/System.out﹕ Request: PUT /db/_local/1103cab91f0be83bb51e2671b97324671205d0c3 HTTP/1.1
03-19 20:14:32.879 1329-1372/? I/System.out﹕ Response: Buffer[size=78 md5=47ba0d0cac66914bed1ff4228c5b9255]
03-19 20:14:32.879 1329-1368/? V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ee6490: RemoteRequest called httpClient.execute, url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.879 1329-1368/? V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ee6490: RemoteRequest finally block. url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.889 1329-1368/? V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ee6490: RemoteRequest calling respondWithResult. url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3, error: null
03-19 20:14:32.889 1329-1368/? D/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry$1@b1ee0d18: RemoteRequestRetry inner request finished, url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.889 1329-1368/? D/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry$1@b1ee0d18: RemoteRequestRetry was successful, calling callback url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.889 1329-1368/? D/Sync﹕ com.couchbase.lite.replicator.ReplicationInternal$7@b1efc738: put remote _local document request finished. checkpointID: 1103cab91f0be83bb51e2671b97324671205d0c3 body: {lastSequence=2}
03-19 20:14:32.889 1329-1368/? D/Sync﹕ com.couchbase.lite.replicator.ReplicationInternal$7@b1efc738: saved remote checkpoint, updating local checkpoint. remoteCheckpoint: {_rev=0-1, lastSequence=2}
03-19 20:14:32.889 1329-1368/? V/CBLite﹕ com.couchbase.lite.Database[/data/data/com.couchbase.lite.test/files/test/cblite-test.cblite]: setLastSequence() called with lastSequence: 2 checkpointId: 1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.899 1329-1372/? I/MockWebServer﹕ Received request: PUT /db/_local/1103cab91f0be83bb51e2671b97324671205d0c3 HTTP/1.1 and responded: HTTP/1.1 201 OK
03-19 20:14:32.909 1329-1368/? V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ee6490: RemoteRequest run() finished, url: http://localhost:36902/db/_local/1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:32.909 1329-1374/? D/Sync﹕ done calling future.get() on com.couchbase.lite.support.RemoteRequestRetry@b1ecd188
03-19 20:14:32.909 1329-1374/? W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:14:32.919 1329-1347/? D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:14:32.919 1329-1347/? I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:14:32.919 1329-1347/? V/Sync﹕ [onEntry()] RUNNING => IDLE
03-19 20:14:32.919 1329-1347/? D/Sync﹕ State transition: RUNNING -> IDLE (via WAITING_FOR_CHANGES). this: com.couchbase.lite.replicator.PullerInternal@b1ef1828
03-19 20:14:32.979 1329-1342/? W/Sync﹕ [fireTrigger()] => STOP_GRACEFUL
03-19 20:14:32.979 1329-1347/? D/Sync﹕ firing trigger: STOP_GRACEFUL
03-19 20:14:32.979 1329-1347/? I/StateMachine﹕ Firing STOP_GRACEFUL
03-19 20:14:32.989 1329-1347/? V/Sync﹕ [onExit()] IDLE => STOPPING
03-19 20:14:32.989 1329-1347/? D/Sync﹕ State transition: IDLE -> STOPPING (via STOP_GRACEFUL). this: com.couchbase.lite.replicator.PullerInternal@b1ef1828
03-19 20:14:32.989 1329-1347/? V/Sync﹕ [onExit()] IDLE => STOPPING
03-19 20:14:32.989 1329-1347/? V/Sync﹕ [onEntry()] IDLE => STOPPING
03-19 20:14:32.989 1329-1347/? D/Sync﹕ stopGraceful()
03-19 20:14:32.989 1329-1347/? D/Sync﹕ PullerInternal stopGraceful()
03-19 20:14:32.989 1329-1347/? D/Sync﹕ State transition: IDLE -> STOPPING (via STOP_GRACEFUL). this: com.couchbase.lite.replicator.PullerInternal@b1ef1828
03-19 20:14:32.989 1329-1377/? D/Sync﹕ batcher.waitForPendingFutures()
03-19 20:14:32.989 1329-1377/? D/Batcher﹕ com.couchbase.lite.support.Batcher@b1e9a778: waitForPendingFutures
03-19 20:14:32.989 1329-1377/? D/Batcher﹕ com.couchbase.lite.support.Batcher@b1e9a778: /waitForPendingFutures
03-19 20:14:32.989 1329-1377/? D/Sync﹕ waitForPendingFutures()
03-19 20:14:32.999 1329-1377/? D/Sync﹕ downloadsToInsert.waitForPendingFutures()
03-19 20:14:32.999 1329-1377/? D/Batcher﹕ com.couchbase.lite.support.Batcher@b1e87fd0: waitForPendingFutures
03-19 20:14:32.999 1329-1377/? D/Batcher﹕ com.couchbase.lite.support.Batcher@b1e87fd0: /waitForPendingFutures
03-19 20:14:32.999 1329-1377/? D/Sync﹕ stopping change tracker
03-19 20:14:32.999 1329-1377/? D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e4ceb0: Changed tracker asked to stop
03-19 20:14:33.009 1329-1377/? D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e4ceb0: Changed tracker aborting request: org.apache.http.client.methods.HttpGet@b1ec41d8
03-19 20:14:33.019 1329-1377/? D/Sync﹕ stopped change tracker
03-19 20:14:33.019 1329-1377/? W/Sync﹕ [fireTrigger()] => STOP_IMMEDIATE
03-19 20:14:33.019 1329-1347/? D/Sync﹕ firing trigger: STOP_IMMEDIATE
03-19 20:14:33.019 1329-1347/? I/StateMachine﹕ Firing STOP_IMMEDIATE
03-19 20:14:33.019 1329-1347/? V/Sync﹕ [onEntry()] STOPPING => STOPPED
03-19 20:14:33.019 1329-1347/? V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1ef1828: clearDbRef() called
03-19 20:14:33.019 1329-1347/? V/CBLite﹕ com.couchbase.lite.Database[/data/data/com.couchbase.lite.test/files/test/cblite-test.cblite]: setLastSequence() called with lastSequence: 2 checkpointId: 1103cab91f0be83bb51e2671b97324671205d0c3
03-19 20:14:33.029 1329-1377/? E/Sync﹕ PullerInternal stopGraceful.run() finished
03-19 20:14:33.029 1329-1347/? V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1ef1828: clearDbRef() setting db to null
03-19 20:14:33.049 1329-1347/? D/Sync﹕ State transition: STOPPING -> STOPPED (via STOP_IMMEDIATE). this: com.couchbase.lite.replicator.PullerInternal@b1ef1828
03-19 20:14:33.049 1329-1342/? V/LiteTestCase﹕ tearDown
03-19 20:14:33.059 1329-1342/? V/Database﹕ AndroidSQLiteStorageEngine{database=b1e76a88}: Closed Android sqlite db
03-19 20:14:33.059 1329-1342/? I/CBLite﹕ Closing com.couchbase.lite.Manager@b1e2a2e0
03-19 20:14:36.029 1329-1347/? D/Sync﹕ com.couchbase.lite.replicator.PullerInternal$10@b1f29770 still no longer running, not restarting change tracker
03-19 20:14:36.109 1329-1347/? D/Sync﹕ com.couchbase.lite.replicator.PullerInternal$10@b1e8dfb8 still no longer running, not restarting change tracker
03-19 20:14:36.109 1329-1342/? I/CBLite﹕ Closed com.couchbase.lite.Manager@b1e2a2e0
03-19 20:14:36.109 1329-1342/? I/TestRunner﹕ finished: testGoOffline(com.couchbase.lite.replicator.ReplicationTest)
03-19 20:14:36.109 1329-1342/? I/TestRunner﹕ passed: testGoOffline(com.couchbase.lite.replicator.ReplicationTest)
03-19 20:14:36.129 378-493/system_process I/ActivityManager﹕ Force stopping com.couchbase.lite.test appid=10052 user=0: finished inst
03-19 20:14:36.129 378-493/system_process I/ActivityManager﹕ Killing 1329:com.couchbase.lite.test/u0a52 (adj 0): stop com.couchbase.lite.test
03-19 20:14:36.139 1319-1319/? D/AndroidRuntime﹕ Shutting down VM
03-19 20:14:36.159 1319-1325/? D/dalvikvm﹕ Debugger has detached; object registry had 1 entries
03-19 20:15:00.999 378-417/system_process D/ConnectivityService﹕ Sampling interval elapsed, updating statistics ..
03-19 20:15:01.009 378-417/system_process D/ConnectivityService﹕ Done.
03-19 20:15:01.009 378-417/system_process D/ConnectivityService﹕ Setting timer for 720seconds
03-19 20:15:46.599 378-417/system_process D/MobileDataStateTracker﹕ default: setPolicyDataEnable(enabled=true)
03-19 20:15:47.719 378-417/system_process D/MobileDataStateTracker﹕ default: setPolicyDataEnable(enabled=true)
03-19 20:15:48.549 1385-1385/? D/AndroidRuntime﹕ >>>>>> AndroidRuntime START com.android.internal.os.RuntimeInit <<<<<<
03-19 20:15:48.559 1385-1385/? D/AndroidRuntime﹕ CheckJNI is ON
03-19 20:15:48.669 1385-1385/? D/dalvikvm﹕ Trying to load lib libjavacore.so 0x0
03-19 20:15:48.679 1385-1385/? D/dalvikvm﹕ Added shared lib libjavacore.so 0x0
03-19 20:15:48.699 1385-1385/? D/dalvikvm﹕ Trying to load lib libnativehelper.so 0x0
03-19 20:15:48.699 1385-1385/? D/dalvikvm﹕ Added shared lib libnativehelper.so 0x0
03-19 20:15:48.699 1385-1385/? D/dalvikvm﹕ No JNI_OnLoad found in libnativehelper.so 0x0, skipping init
03-19 20:15:48.949 1385-1385/? D/dalvikvm﹕ Note: class Landroid/app/ActivityManagerNative; has 179 unimplemented (abstract) methods
03-19 20:15:49.399 1385-1385/? E/memtrack﹕ Couldn't load memtrack module (No such file or directory)
03-19 20:15:49.399 1385-1385/? E/android.os.Debug﹕ failed to load memtrack module: -2
03-19 20:15:49.699 1385-1385/? D/AndroidRuntime﹕ Calling main entry com.android.commands.pm.Pm
03-19 20:15:49.769 378-401/system_process W/ActivityManager﹕ No content provider found for permission revoke: file:///data/local/tmp/com.couchbase.lite.test
03-19 20:15:49.849 378-401/system_process W/ActivityManager﹕ No content provider found for permission revoke: file:///data/local/tmp/com.couchbase.lite.test
03-19 20:15:49.849 378-401/system_process I/PackageManager﹕ Copying native libraries to /data/app-lib/vmdl-2059948122
03-19 20:15:49.939 378-401/system_process D/dalvikvm﹕ GC_FOR_ALLOC freed 752K, 20% free 6354K/7848K, paused 46ms, total 47ms
03-19 20:15:50.429 378-393/system_process I/ActivityManager﹕ Force stopping com.couchbase.lite.test appid=10052 user=-1: uninstall pkg
03-19 20:15:50.479 378-401/system_process W/PackageSettings﹕ Skipping PackageSetting{b1ea9438 self.hideki.issue447/10054} due to missing metadata
03-19 20:15:50.509 378-401/system_process I/PackageManager﹕ Package com.couchbase.lite.test codePath changed from /data/app/com.couchbase.lite.test-1.apk to /data/app/com.couchbase.lite.test-2.apk; Retaining data and using new
03-19 20:15:50.519 378-401/system_process I/PackageManager﹕ Running dexopt on: com.couchbase.lite.test
03-19 20:15:55.249 1396-1396/? D/dalvikvm﹕ DexOpt: load 309ms, verify+opt 3555ms, 2897052 bytes
03-19 20:15:55.459 378-401/system_process W/PackageManager﹕ Code path for pkg : com.couchbase.lite.test changing from /data/app/com.couchbase.lite.test-1.apk to /data/app/com.couchbase.lite.test-2.apk
03-19 20:15:55.459 378-401/system_process W/PackageManager﹕ Resource path for pkg : com.couchbase.lite.test changing from /data/app/com.couchbase.lite.test-1.apk to /data/app/com.couchbase.lite.test-2.apk
03-19 20:15:55.529 378-401/system_process D/dalvikvm﹕ GC_FOR_ALLOC freed 761K, 19% free 6393K/7848K, paused 61ms, total 61ms
03-19 20:15:55.529 378-393/system_process I/ActivityManager﹕ Force stopping com.couchbase.lite.test appid=10052 user=-1: update pkg
03-19 20:15:55.589 378-401/system_process W/PackageSettings﹕ Skipping PackageSetting{b1ea9438 self.hideki.issue447/10054} due to missing metadata
03-19 20:15:55.659 378-401/system_process W/PackageSettings﹕ Skipping PackageSetting{b1ea9438 self.hideki.issue447/10054} due to missing metadata
03-19 20:15:55.679 378-401/system_process I/ActivityManager﹕ Force stopping com.couchbase.lite.test appid=10052 user=0: pkg removed
03-19 20:15:55.759 378-407/system_process I/InputReader﹕ Reconfiguring input devices. changes=0x00000010
03-19 20:15:55.809 378-493/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:55.809 378-493/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:55.809 378-493/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:55.819 378-493/system_process I/PackageManager﹕ Scheme: "sms"
03-19 20:15:55.849 378-378/system_process D/BackupManagerService﹕ Received broadcast Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:com.couchbase.lite.test flg=0x4000010 (has extras) }
03-19 20:15:55.859 378-597/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:55.859 378-597/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:55.859 378-597/system_process I/PackageManager﹕ Scheme: "smsto"
03-19 20:15:55.859 378-597/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:55.889 378-390/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:55.889 378-390/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:55.889 378-390/system_process I/PackageManager﹕ Scheme: "mms"
03-19 20:15:55.889 378-390/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:55.939 378-389/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:55.939 378-389/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:55.939 378-389/system_process I/PackageManager﹕ Scheme: "mmsto"
03-19 20:15:55.939 378-389/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.019 527-527/com.android.phone D/dalvikvm﹕ GC_FOR_ALLOC freed 470K, 18% free 3798K/4592K, paused 23ms, total 25ms
03-19 20:15:56.029 378-390/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.029 378-390/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.039 378-390/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.039 378-390/system_process I/PackageManager﹕ Scheme: "sms"
03-19 20:15:56.099 378-390/system_process D/dalvikvm﹕ GC_FOR_ALLOC freed 880K, 20% free 6325K/7848K, paused 54ms, total 55ms
03-19 20:15:56.129 378-389/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.129 378-389/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.129 378-389/system_process I/PackageManager﹕ Scheme: "smsto"
03-19 20:15:56.129 378-389/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.169 378-494/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.169 378-494/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.169 378-494/system_process I/PackageManager﹕ Scheme: "mms"
03-19 20:15:56.169 378-494/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.229 378-407/system_process I/InputReader﹕ Reconfiguring input devices. changes=0x00000010
03-19 20:15:56.309 378-494/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.309 378-494/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.309 378-494/system_process I/PackageManager﹕ Scheme: "mmsto"
03-19 20:15:56.309 378-494/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.329 378-378/system_process D/BackupManagerService﹕ Received broadcast Intent { act=android.intent.action.PACKAGE_ADDED dat=package:com.couchbase.lite.test flg=0x4000010 (has extras) }
03-19 20:15:56.329 378-378/system_process V/BackupManagerService﹕ removePackageParticipantsLocked: uid=10052 #1
03-19 20:15:56.379 378-378/system_process V/BackupManagerService﹕ addPackageParticipantsLocked: #1
03-19 20:15:56.419 378-556/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.419 378-556/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.419 378-556/system_process I/PackageManager﹕ Scheme: "sms"
03-19 20:15:56.419 378-556/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.479 527-527/com.android.phone D/dalvikvm﹕ GC_FOR_ALLOC freed 432K, 19% free 3751K/4592K, paused 30ms, total 32ms
03-19 20:15:56.499 378-596/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.499 378-596/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.499 378-596/system_process I/PackageManager﹕ Scheme: "smsto"
03-19 20:15:56.499 378-596/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.529 378-389/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.529 378-389/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.529 378-389/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.539 378-389/system_process I/PackageManager﹕ Scheme: "mms"
03-19 20:15:56.599 378-756/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.599 378-756/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.599 378-756/system_process I/PackageManager﹕ Scheme: "mmsto"
03-19 20:15:56.599 378-756/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.629 1062-1062/com.android.keychain W/ContextImpl﹕ Calling a method in the system process without a qualified user: android.app.ContextImpl.startService:1479 android.content.ContextWrapper.startService:494 android.content.ContextWrapper.startService:494 com.android.keychain.KeyChainBroadcastReceiver.onReceive:12 android.app.ActivityThread.handleReceiver:2419
03-19 20:15:56.679 378-756/system_process D/dalvikvm﹕ GC_FOR_ALLOC freed 787K, 20% free 6330K/7848K, paused 69ms, total 70ms
03-19 20:15:56.719 378-596/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.719 378-596/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.719 378-596/system_process I/PackageManager﹕ Scheme: "sms"
03-19 20:15:56.719 378-596/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.749 378-389/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.749 378-389/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.749 378-389/system_process I/PackageManager﹕ Scheme: "smsto"
03-19 20:15:56.749 378-389/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.789 378-494/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.789 378-494/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.789 378-494/system_process I/PackageManager﹕ Scheme: "mms"
03-19 20:15:56.789 378-494/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.849 378-407/system_process I/InputReader﹕ Reconfiguring input devices. changes=0x00000010
03-19 20:15:56.899 527-527/com.android.phone D/dalvikvm﹕ GC_FOR_ALLOC freed 403K, 18% free 3797K/4592K, paused 19ms, total 20ms
03-19 20:15:56.899 378-423/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.899 378-423/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.909 378-423/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.909 378-423/system_process I/PackageManager﹕ Scheme: "mmsto"
03-19 20:15:56.949 378-556/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.949 378-556/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.949 378-556/system_process I/PackageManager﹕ Scheme: "sms"
03-19 20:15:56.949 378-556/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.979 378-596/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:56.979 378-596/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:56.979 378-596/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:56.989 378-596/system_process I/PackageManager﹕ Scheme: "smsto"
03-19 20:15:57.029 378-597/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:57.029 378-597/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:57.029 378-597/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:57.039 378-597/system_process I/PackageManager﹕ Scheme: "mms"
03-19 20:15:57.119 378-597/system_process D/dalvikvm﹕ GC_FOR_ALLOC freed 762K, 19% free 6364K/7848K, paused 47ms, total 48ms
03-19 20:15:57.139 378-389/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:57.139 378-389/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:57.139 378-389/system_process I/PackageManager﹕ Scheme: "mmsto"
03-19 20:15:57.139 378-389/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:57.179 378-423/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:57.179 378-423/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:57.179 378-423/system_process I/PackageManager﹕ Scheme: "sms"
03-19 20:15:57.179 378-423/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:57.239 527-527/com.android.phone D/dalvikvm﹕ GC_FOR_ALLOC freed 416K, 18% free 3796K/4592K, paused 29ms, total 30ms
03-19 20:15:57.249 378-597/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:57.249 378-597/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:57.259 378-597/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:57.259 378-597/system_process I/PackageManager﹕ Scheme: "smsto"
03-19 20:15:57.289 378-494/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:57.289 378-494/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:57.289 378-494/system_process I/PackageManager﹕ Scheme: "mms"
03-19 20:15:57.289 378-494/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:57.319 378-493/system_process I/PackageManager﹕ Action: "android.intent.action.SENDTO"
03-19 20:15:57.319 378-493/system_process I/PackageManager﹕ Category: "android.intent.category.DEFAULT"
03-19 20:15:57.319 378-493/system_process I/PackageManager﹕ Adding preferred activity ComponentInfo{com.android.mms/com.android.mms.ui.ComposeMessageActivity} for user 0 :
03-19 20:15:57.329 378-493/system_process I/PackageManager﹕ Scheme: "mmsto"
03-19 20:15:57.549 378-401/system_process D/dalvikvm﹕ GC_EXPLICIT freed 609K, 20% free 6331K/7848K, paused 4ms+13ms, total 336ms
03-19 20:15:57.599 1385-1385/? D/AndroidRuntime﹕ Shutting down VM
03-19 20:15:57.609 1385-1391/? D/jdwp﹕ Got wake-up signal, bailing out of select
03-19 20:15:57.609 1385-1391/? D/dalvikvm﹕ Debugger has detached; object registry had 1 entries
03-19 20:15:57.709 378-394/system_process W/RecognitionManagerService﹕ no available voice recognition services found for user 0
03-19 20:15:58.559 1402-1402/? D/AndroidRuntime﹕ >>>>>> AndroidRuntime START com.android.internal.os.RuntimeInit <<<<<<
03-19 20:15:58.569 1402-1402/? D/AndroidRuntime﹕ CheckJNI is ON
03-19 20:15:58.639 1402-1402/? D/dalvikvm﹕ Trying to load lib libjavacore.so 0x0
03-19 20:15:58.649 1402-1402/? D/dalvikvm﹕ Added shared lib libjavacore.so 0x0
03-19 20:15:58.679 1402-1402/? D/dalvikvm﹕ Trying to load lib libnativehelper.so 0x0
03-19 20:15:58.679 1402-1402/? D/dalvikvm﹕ Added shared lib libnativehelper.so 0x0
03-19 20:15:58.689 1402-1402/? D/dalvikvm﹕ No JNI_OnLoad found in libnativehelper.so 0x0, skipping init
03-19 20:15:58.919 1402-1402/? D/dalvikvm﹕ Note: class Landroid/app/ActivityManagerNative; has 179 unimplemented (abstract) methods
03-19 20:15:59.359 1402-1402/? E/memtrack﹕ Couldn't load memtrack module (No such file or directory)
03-19 20:15:59.359 1402-1402/? E/android.os.Debug﹕ failed to load memtrack module: -2
03-19 20:15:59.669 1402-1402/? D/AndroidRuntime﹕ Calling main entry com.android.commands.am.Am
03-19 20:15:59.729 378-597/system_process I/ActivityManager﹕ Force stopping com.couchbase.lite.test appid=10052 user=0: start instr
03-19 20:15:59.759 1412-1412/com.couchbase.lite.test D/dalvikvm﹕ Not late-enabling CheckJNI (already on)
03-19 20:15:59.769 378-597/system_process I/ActivityManager﹕ Start proc com.couchbase.lite.test for added application com.couchbase.lite.test: pid=1412 uid=10052 gids={50052, 3003}
03-19 20:16:00.079 1412-1425/com.couchbase.lite.test I/TestRunner﹕ started: testGoOffline(com.couchbase.lite.replicator.ReplicationTest)
03-19 20:16:00.239 1412-1425/com.couchbase.lite.test D/dalvikvm﹕ GC_FOR_ALLOC freed 287K, 15% free 3386K/3956K, paused 27ms, total 28ms
03-19 20:16:00.349 1412-1425/com.couchbase.lite.test I/CBLite﹕ Starting Manager version: devbuild
03-19 20:16:00.359 1412-1425/com.couchbase.lite.test W/CBLite﹕ mustExist is true and db (cblite-test) does not exist
03-19 20:16:00.419 1412-1425/com.couchbase.lite.test V/Database﹕ AndroidSQLiteStorageEngine{database=b1e22bc8}: Opened Android sqlite db
03-19 20:16:00.419 1412-1425/com.couchbase.lite.test D/dalvikvm﹕ Trying to load lib /data/app-lib/com.couchbase.lite.test-2/libcom_couchbase_touchdb_TDCollateJSON.so 0xb1e30e88
03-19 20:16:00.419 1412-1425/com.couchbase.lite.test D/dalvikvm﹕ Added shared lib /data/app-lib/com.couchbase.lite.test-2/libcom_couchbase_touchdb_TDCollateJSON.so 0xb1e30e88
03-19 20:16:00.429 1412-1425/com.couchbase.lite.test V/TDCollateJSON﹕ SQLite3 handle is -1190763880
03-19 20:16:00.429 1412-1425/com.couchbase.lite.test D/dalvikvm﹕ Trying to load lib /data/app-lib/com.couchbase.lite.test-2/libcom_couchbase_touchdb_RevCollator.so 0xb1e30e88
03-19 20:16:00.429 1412-1425/com.couchbase.lite.test D/dalvikvm﹕ Added shared lib /data/app-lib/com.couchbase.lite.test-2/libcom_couchbase_touchdb_RevCollator.so 0xb1e30e88
03-19 20:16:00.819 1412-1425/com.couchbase.lite.test D/dalvikvm﹕ GC_FOR_ALLOC freed 368K, 16% free 3532K/4184K, paused 17ms, total 18ms
03-19 20:16:01.009 1412-1425/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => START
03-19 20:16:01.019 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: START
03-19 20:16:01.049 1412-1428/com.couchbase.lite.test D/dalvikvm﹕ GC_FOR_ALLOC freed 414K, 17% free 3630K/4328K, paused 26ms, total 26ms
03-19 20:16:01.049 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing START
03-19 20:16:01.049 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] INITIAL => RUNNING
03-19 20:16:01.129 1412-1428/com.couchbase.lite.test D/Sync﹕ [sendAsyncRequest()] GET => http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.129 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry@b1ea29c8: RemoteRequestRetry created, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.139 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ea8a38: RemoteRequest created, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.139 1412-1428/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => RESUME
03-19 20:16:01.149 1412-1430/com.couchbase.lite.test D/Sync﹕ calling future.get() on com.couchbase.lite.support.RemoteRequestRetry@b1ea29c8
03-19 20:16:01.149 1412-1429/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ea8a38: RemoteRequest run() called, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.159 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: INITIAL -> RUNNING (via START). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:01.159 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: RESUME
03-19 20:16:01.159 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing RESUME
03-19 20:16:01.159 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 0
03-19 20:16:01.169 1412-1429/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ea8a38: RemoteRequest calling httpClient.execute, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.169 1412-1429/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ea8a38: RemoteRequest calling httpClient.execute, client: org.apache.http.impl.client.DefaultHttpClient@b1e8a348 url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.209 1412-1432/com.couchbase.lite.test I/System.out﹕ Request: GET /db/_local/e2d56953d893f93c61cbb2655639401ff3193065 HTTP/1.1
03-19 20:16:01.209 1412-1432/com.couchbase.lite.test I/System.out﹕ Response: Buffer[size=0]
03-19 20:16:01.219 1412-1429/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ea8a38: RemoteRequest called httpClient.execute, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.229 1412-1432/com.couchbase.lite.test I/MockWebServer﹕ Received request: GET /db/_local/e2d56953d893f93c61cbb2655639401ff3193065 HTTP/1.1 and responded: HTTP/1.1 404 NOT FOUND
03-19 20:16:01.229 1412-1429/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry$1@b1eedf08: RemoteRequestRetry inner request finished, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.239 1412-1429/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry@b1ea29c8: isTransientError called, httpResponse: org.apache.http.message.BasicHttpResponse@b1e75288 e: org.apache.http.client.HttpResponseException: NOT FOUND
03-19 20:16:01.239 1412-1429/com.couchbase.lite.test D/Sync﹕ %s: return false
03-19 20:16:01.239 1412-1429/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry$1@b1eedf08: RemoteRequestRetry failed, non-transient error. NOT retrying. url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.239 1412-1429/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.ReplicationInternal$9@b1ea5d30: Remote checkpoint does not exist on server yet: e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.239 1412-1429/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.ReplicationInternal$9@b1ea5d30: lastSequence mismatch: I had: null, remote had: null
03-19 20:16:01.249 1412-1429/com.couchbase.lite.test D/Sync﹕ startReplicating()
03-19 20:16:01.249 1412-1429/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: starting ChangeTracker with since=null mode=OneShot
03-19 20:16:01.249 1412-1429/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: started ChangeTracker com.couchbase.lite.replicator.ChangeTracker@b1eda018
03-19 20:16:01.249 1412-1429/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1eda018: Changed tracker asked to start
03-19 20:16:01.259 1412-1429/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ea8a38: RemoteRequest finally block. url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.259 1412-1429/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1ea8a38: RemoteRequest run() finished, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:01.259 1412-1430/com.couchbase.lite.test D/Sync﹕ done calling future.get() on com.couchbase.lite.support.RemoteRequestRetry@b1ea29c8
03-19 20:16:01.259 1412-1430/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:01.269 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:01.269 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:01.269 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] RUNNING => IDLE
03-19 20:16:01.269 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: RUNNING -> IDLE (via WAITING_FOR_CHANGES). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:01.269 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 0
03-19 20:16:01.269 1412-1425/com.couchbase.lite.test D/CBLite﹕ putReplicationOffline: com.couchbase.lite.replicator.Replication@b1eebc60
03-19 20:16:01.269 1412-1425/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => GO_OFFLINE
03-19 20:16:01.269 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: GO_OFFLINE
03-19 20:16:01.279 1412-1433/com.couchbase.lite.test E/ChangeTracker﹕ Thread id => 100
03-19 20:16:01.289 1412-1433/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1eda018: Making request to http://localhost:40340/db/_changes?feed=normal&heartbeat=300000&style=all_docs
03-19 20:16:01.299 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing GO_OFFLINE
03-19 20:16:01.299 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => OFFLINE
03-19 20:16:01.299 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: IDLE -> OFFLINE (via GO_OFFLINE). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:01.299 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] IDLE => OFFLINE
03-19 20:16:01.309 1412-1428/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1eda018: Changed tracker asked to stop
03-19 20:16:01.329 1412-1428/com.couchbase.lite.test D/dalvikvm﹕ GC_FOR_ALLOC freed 447K, 17% free 3696K/4428K, paused 23ms, total 24ms
03-19 20:16:01.339 1412-1428/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1eda018: Changed tracker aborting request: org.apache.http.client.methods.HttpGet@b1f130f8
03-19 20:16:01.339 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: IDLE -> OFFLINE (via GO_OFFLINE). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:01.349 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 0
03-19 20:16:01.349 1412-1433/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1eda018: Change tracker run loop exiting
03-19 20:16:01.349 1412-1433/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1eda018: Change tracker in stopped()
03-19 20:16:01.349 1412-1433/com.couchbase.lite.test W/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1eda018: Change tracker calling changeTrackerStopped, client: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:01.389 1412-1432/com.couchbase.lite.test I/System.out﹕ Request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs HTTP/1.1
03-19 20:16:01.389 1412-1432/com.couchbase.lite.test I/System.out﹕ Response: Buffer[size=77 md5=1c936b31cb16088ddca6918d475804be]
03-19 20:16:01.399 1412-1425/com.couchbase.lite.test D/CBLite﹕ /putReplicationOffline: com.couchbase.lite.replicator.Replication@b1eebc60
03-19 20:16:01.399 1412-1425/com.couchbase.lite.test D/CBLite﹕ putReplicationOnline: com.couchbase.lite.replicator.Replication@b1eebc60
03-19 20:16:01.399 1412-1425/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => GO_ONLINE
03-19 20:16:01.409 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 0
03-19 20:16:01.409 1412-1428/com.couchbase.lite.test D/Sync﹕ changeTrackerStopped. lifecycle: CONTINUOUS
03-19 20:16:01.409 1412-1428/com.couchbase.lite.test D/Sync﹕ Change tracker stopped because we are going offline
03-19 20:16:01.409 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: GO_ONLINE
03-19 20:16:01.409 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing GO_ONLINE
03-19 20:16:01.419 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] OFFLINE => RUNNING
03-19 20:16:01.419 1412-1428/com.couchbase.lite.test D/Sync﹕ startReplicating()
03-19 20:16:01.419 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: starting ChangeTracker with since=null mode=OneShot
03-19 20:16:01.419 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: started ChangeTracker com.couchbase.lite.replicator.ChangeTracker@b1ebbf18
03-19 20:16:01.419 1412-1428/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: Changed tracker asked to start
03-19 20:16:01.419 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: OFFLINE -> RUNNING (via GO_ONLINE). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:01.419 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 0
03-19 20:16:01.419 1412-1425/com.couchbase.lite.test D/CBLite﹕ /putReplicationOnline: com.couchbase.lite.replicator.Replication@b1eebc60
03-19 20:16:01.419 1412-1435/com.couchbase.lite.test E/ChangeTracker﹕ Thread id => 102
03-19 20:16:01.439 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: Making request to http://localhost:40340/db/_changes?feed=normal&heartbeat=300000&style=all_docs
03-19 20:16:01.449 1412-1437/com.couchbase.lite.test I/System.out﹕ Request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs HTTP/1.1
03-19 20:16:01.449 1412-1437/com.couchbase.lite.test I/System.out﹕ Response: Buffer[size=14 data=7b22726573756c7473223a5b5d7d]
03-19 20:16:01.459 1412-1437/com.couchbase.lite.test I/MockWebServer﹕ Received request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs HTTP/1.1 and responded: HTTP/1.1 200 OK
03-19 20:16:01.459 1412-1432/com.couchbase.lite.test W/MockWebServer﹕ MockWebServer connection failed
java.net.SocketException: sendto failed: EPIPE (Broken pipe)
at libcore.io.IoBridge.maybeThrowAfterSendto(IoBridge.java:499)
at libcore.io.IoBridge.sendto(IoBridge.java:468)
at java.net.PlainSocketImpl.write(PlainSocketImpl.java:507)
at java.net.PlainSocketImpl.access$100(PlainSocketImpl.java:46)
at java.net.PlainSocketImpl$PlainSocketOutputStream.write(PlainSocketImpl.java:269)
at java.io.BufferedOutputStream.flushInternal(BufferedOutputStream.java:185)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:85)
at com.squareup.okhttp.mockwebserver.MockWebServer.throttledTransfer(MockWebServer.java:576)
at com.squareup.okhttp.mockwebserver.MockWebServer.writeResponse(MockWebServer.java:555)
at com.squareup.okhttp.mockwebserver.MockWebServer.access$1700(MockWebServer.java:79)
at com.squareup.okhttp.mockwebserver.MockWebServer$3.processOneRequest(MockWebServer.java:424)
at com.squareup.okhttp.mockwebserver.MockWebServer$3.processConnection(MockWebServer.java:382)
at com.squareup.okhttp.mockwebserver.MockWebServer$3.execute(MockWebServer.java:327)
at com.squareup.okhttp.internal.NamedRunnable.run(NamedRunnable.java:33)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at java.lang.Thread.run(Thread.java:841)
Caused by: libcore.io.ErrnoException: sendto failed: EPIPE (Broken pipe)
at libcore.io.Posix.sendtoBytes(Native Method)
at libcore.io.Posix.sendto(Posix.java:156)
at libcore.io.BlockGuardOs.sendto(BlockGuardOs.java:177)
at libcore.io.IoBridge.sendto(IoBridge.java:466)
            at java.net.PlainSocketImpl.write(PlainSocketImpl.java:507)
            at java.net.PlainSocketImpl.access$100(PlainSocketImpl.java:46)
            at java.net.PlainSocketImpl$PlainSocketOutputStream.write(PlainSocketImpl.java:269)
            at java.io.BufferedOutputStream.flushInternal(BufferedOutputStream.java:185)
            at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:85)
            at com.squareup.okhttp.mockwebserver.MockWebServer.throttledTransfer(MockWebServer.java:576)
            at com.squareup.okhttp.mockwebserver.MockWebServer.writeResponse(MockWebServer.java:555)
            at com.squareup.okhttp.mockwebserver.MockWebServer.access$1700(MockWebServer.java:79)
            at com.squareup.okhttp.mockwebserver.MockWebServer$3.processOneRequest(MockWebServer.java:424)
            at com.squareup.okhttp.mockwebserver.MockWebServer$3.processConnection(MockWebServer.java:382)
            at com.squareup.okhttp.mockwebserver.MockWebServer$3.execute(MockWebServer.java:327)
            at com.squareup.okhttp.internal.NamedRunnable.run(NamedRunnable.java:33)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
            at java.lang.Thread.run(Thread.java:841)
03-19 20:16:01.459 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: got response. status: HTTP/1.1 200 OK mode: OneShot
03-19 20:16:01.469 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: /entity.getContent(). mode: OneShot
03-19 20:16:01.469 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: readValue (oneshot)
03-19 20:16:01.469 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: /readValue (oneshot)
03-19 20:16:01.469 1412-1435/com.couchbase.lite.test E/Sync﹕ changeTrackerCaughtUp
03-19 20:16:01.479 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: Making request to http://localhost:40340/db/_changes?feed=longpoll&limit=50&heartbeat=300000&style=all_docs
03-19 20:16:01.489 1412-1437/com.couchbase.lite.test I/System.out﹕ Request: GET /db/_changes?feed=longpoll&limit=50&heartbeat=300000&style=all_docs HTTP/1.1
03-19 20:16:01.489 1412-1437/com.couchbase.lite.test I/System.out﹕ Response: Buffer[size=77 md5=0ff38cb5b5563a57852ad3a48c61f7a4]
03-19 20:16:01.489 1412-1437/com.couchbase.lite.test I/MockWebServer﹕ Received request: GET /db/_changes?feed=longpoll&limit=50&heartbeat=300000&style=all_docs HTTP/1.1 and responded: HTTP/1.1 200 OK
03-19 20:16:01.499 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: got response. status: HTTP/1.1 200 OK mode: LongPoll
03-19 20:16:01.499 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: /entity.getContent(). mode: LongPoll
03-19 20:16:01.499 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: readValue
03-19 20:16:01.559 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: /readValue. fullBody: {results=[{id=doc2, seq=2, changes=[{rev=1-563b}]}], last_seq=2}
03-19 20:16:01.559 1412-1435/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: changeTrackerReceivedChange: {id=doc2, seq=2, changes=[{rev=1-563b}]}
03-19 20:16:01.569 1412-1428/com.couchbase.lite.test D/Sync﹕ changeTrackerReceivedChange: {id=doc2, seq=2, changes=[{rev=1-563b}]}
03-19 20:16:01.569 1412-1428/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: adding rev to inbox {doc2 #1-563b}
03-19 20:16:01.569 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: changeTrackerReceivedChange() incrementing changesCount by 1
03-19 20:16:01.569 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: Incrementing changesCount count from 0 by adding 1 -> 1
03-19 20:16:01.579 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: addToInbox() called, rev: {doc2 #1-563b}. Thread: Thread[CBLManagerWorkExecutor,5,main]
03-19 20:16:01.579 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: queueObjects called with 1 objects. Thread: Thread[CBLManagerWorkExecutor,5,main]
03-19 20:16:01.579 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: inbox size before adding objects: 0
03-19 20:16:01.579 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: calling scheduleWithDelay(500)
03-19 20:16:01.579 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: scheduleWithDelay called with delayMs: 500 ms
03-19 20:16:01.579 1412-1428/com.couchbase.lite.test V/Batcher﹕ workExecutor.schedule() with delayMs: 500 ms
03-19 20:16:01.579 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: created future: java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@b1eb6130
03-19 20:16:01.579 1412-1428/com.couchbase.lite.test V/CBLite﹕ setPaused: false
03-19 20:16:01.579 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 0
03-19 20:16:01.579 1412-1435/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: /changeTrackerReceivedChange: {id=doc2, seq=2, changes=[{rev=1-563b}]}
03-19 20:16:01.589 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: responseOK: true
03-19 20:16:01.589 1412-1435/com.couchbase.lite.test E/Sync﹕ changeTrackerCaughtUp
03-19 20:16:01.589 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: Starting new longpoll
03-19 20:16:01.609 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: Making request to http://localhost:40340/db/_changes?feed=longpoll&limit=50&heartbeat=300000&style=all_docs&since=2
03-19 20:16:01.629 1412-1437/com.couchbase.lite.test I/System.out﹕ Request: GET /db/_changes?feed=longpoll&limit=50&heartbeat=300000&style=all_docs&since=2 HTTP/1.1
03-19 20:16:01.639 1412-1435/com.couchbase.lite.test E/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: Change tracker got error 406
03-19 20:16:01.639 1412-1435/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: Change tracker run loop exiting
03-19 20:16:01.649 1412-1435/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: Change tracker in stopped()
03-19 20:16:01.649 1412-1435/com.couchbase.lite.test W/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ebbf18: Change tracker calling changeTrackerStopped, client: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:01.649 1412-1428/com.couchbase.lite.test D/Sync﹕ changeTrackerStopped. lifecycle: CONTINUOUS
03-19 20:16:01.649 1412-1428/com.couchbase.lite.test E/Sync﹕ Change tracker stopped during continuous replication
03-19 20:16:01.649 1412-1428/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:01.649 1412-1428/com.couchbase.lite.test D/Sync﹕ Scheduling change tracker restart in 10000 ms
03-19 20:16:01.649 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:01.649 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:01.649 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] RUNNING => IDLE
03-19 20:16:01.659 1412-1437/com.couchbase.lite.test I/MockWebServer﹕ Received request: GET /db/_changes?feed=longpoll&limit=50&heartbeat=300000&style=all_docs&since=2 HTTP/1.1 and responded: HTTP/1.1 406 NOT ACCEPTABLE
03-19 20:16:01.659 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: RUNNING -> IDLE (via WAITING_FOR_CHANGES). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:01.659 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 0
03-19 20:16:01.989 1412-1438/com.couchbase.lite.test E/Sync﹕ batcher.waitForPendingFutures()
03-19 20:16:01.989 1412-1438/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: waitForPendingFutures
03-19 20:16:01.989 1412-1438/com.couchbase.lite.test D/Batcher﹕ calling future.get() on java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@b1eb6130
03-19 20:16:02.089 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: processNow() called
03-19 20:16:02.089 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: inbox.size() <= capacity, adding 1 items from inbox -> toProcess
03-19 20:16:02.089 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: invoking processor com.couchbase.lite.replicator.ReplicationInternal$2@b1ea05a0 with 1 items
03-19 20:16:02.089 1412-1428/com.couchbase.lite.test V/Sync﹕ *** com.couchbase.lite.replicator.ReplicationInternal$2@b1ea05a0: BEGIN processInbox (1 sequences)
03-19 20:16:02.089 1412-1428/com.couchbase.lite.test D/Sync﹕ processInbox called
03-19 20:16:02.099 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: fetching 1 remote revisions...
03-19 20:16:02.099 1412-1428/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: pullRemoteRevision with rev: {doc2 #1-563b}
03-19 20:16:02.099 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry@b1ef4400: RemoteRequestRetry created, url: http://localhost:40340/db/doc2?rev=1-563b&revs=true&attachments=true
03-19 20:16:02.099 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteMultipartDownloaderRequest@b1ed4bf0: RemoteRequest created, url: http://localhost:40340/db/doc2?rev=1-563b&revs=true&attachments=true
03-19 20:16:02.099 1412-1428/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => RESUME
03-19 20:16:02.109 1412-1439/com.couchbase.lite.test E/Sync﹕ batcher.waitForPendingFutures()
03-19 20:16:02.119 1412-1439/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: waitForPendingFutures
03-19 20:16:02.119 1412-1439/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: /waitForPendingFutures
03-19 20:16:02.119 1412-1439/com.couchbase.lite.test E/Sync﹕ waitForPendingFutures()
03-19 20:16:02.119 1412-1439/com.couchbase.lite.test D/Sync﹕ calling future.get() on com.couchbase.lite.support.RemoteRequestRetry@b1ef4400
03-19 20:16:02.119 1412-1428/com.couchbase.lite.test V/CBLite﹕ setPaused: false
03-19 20:16:02.119 1412-1428/com.couchbase.lite.test V/Sync﹕ *** com.couchbase.lite.replicator.ReplicationInternal$2@b1ea05a0: END processInbox (lastSequence=null)
03-19 20:16:02.119 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: RESUME
03-19 20:16:02.129 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing RESUME
03-19 20:16:02.129 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => RUNNING
03-19 20:16:02.129 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: IDLE -> RUNNING (via RESUME). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:02.129 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 0
03-19 20:16:02.129 1412-1438/com.couchbase.lite.test D/Batcher﹕ done calling future.get() on java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@b1eb6130
03-19 20:16:02.129 1412-1438/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: /waitForPendingFutures
03-19 20:16:02.129 1412-1438/com.couchbase.lite.test E/Sync﹕ waitForPendingFutures()
03-19 20:16:02.129 1412-1442/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:02.179 1412-1432/com.couchbase.lite.test D/dalvikvm﹕ GC_FOR_ALLOC freed 397K, 16% free 3796K/4484K, paused 22ms, total 23ms
03-19 20:16:02.179 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:02.179 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:02.189 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] RUNNING => IDLE
03-19 20:16:02.189 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: RUNNING -> IDLE (via WAITING_FOR_CHANGES). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:02.189 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 0
03-19 20:16:02.189 1412-1432/com.couchbase.lite.test I/System.out﹕ Request: GET /db/doc2?rev=1-563b&revs=true&attachments=true HTTP/1.1
03-19 20:16:02.189 1412-1432/com.couchbase.lite.test I/System.out﹕ Response: Buffer[size=161 md5=85fd9d94eb895e2af2913b67a3285bda]
03-19 20:16:02.199 1412-1432/com.couchbase.lite.test I/MockWebServer﹕ Received request: GET /db/doc2?rev=1-563b&revs=true&attachments=true HTTP/1.1 and responded: HTTP/1.1 200 OK
03-19 20:16:02.199 1412-1429/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry$1@b1e92fb0: RemoteRequestRetry inner request finished, url: http://localhost:40340/db/doc2?rev=1-563b&revs=true&attachments=true
03-19 20:16:02.199 1412-1429/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry$1@b1e92fb0: RemoteRequestRetry was successful, calling callback url: http://localhost:40340/db/doc2?rev=1-563b&revs=true&attachments=true
03-19 20:16:02.209 1412-1429/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: pullRemoteRevision add rev: {doc2 #1-563b} to batcher: com.couchbase.lite.support.Batcher@b1ed1dc0
03-19 20:16:02.209 1412-1429/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: queueObjects called with 1 objects. Thread: Thread[CBLRequestWorker-e2d56-0,5,main]
03-19 20:16:02.209 1412-1429/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: inbox size before adding objects: 0
03-19 20:16:02.219 1412-1429/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: calling scheduleWithDelay(1000)
03-19 20:16:02.219 1412-1429/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: scheduleWithDelay called with delayMs: 1000 ms
03-19 20:16:02.219 1412-1429/com.couchbase.lite.test V/Batcher﹕ workExecutor.schedule() with delayMs: 1000 ms
03-19 20:16:02.219 1412-1429/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: created future: java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@b1ec72d8
03-19 20:16:02.219 1412-1429/com.couchbase.lite.test D/RemoteRequest﹕ com.couchbase.lite.support.RemoteMultipartDownloaderRequest@b1ed4bf0: executeRequest() finally
03-19 20:16:02.219 1412-1439/com.couchbase.lite.test D/Sync﹕ done calling future.get() on com.couchbase.lite.support.RemoteRequestRetry@b1ef4400
03-19 20:16:03.139 1412-1438/com.couchbase.lite.test E/Sync﹕ downloadsToInsert.waitForPendingFutures()
03-19 20:16:03.139 1412-1438/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: waitForPendingFutures
03-19 20:16:03.139 1412-1438/com.couchbase.lite.test D/Batcher﹕ calling future.get() on java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@b1ec72d8
03-19 20:16:03.219 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: processNow() called
03-19 20:16:03.219 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: inbox.size() <= capacity, adding 1 items from inbox -> toProcess
03-19 20:16:03.219 1412-1439/com.couchbase.lite.test E/Sync﹕ downloadsToInsert.waitForPendingFutures()
03-19 20:16:03.219 1412-1428/com.couchbase.lite.test V/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: invoking processor com.couchbase.lite.replicator.PullerInternal$1@b1ec0290 with 1 items
03-19 20:16:03.229 1412-1439/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: waitForPendingFutures
03-19 20:16:03.229 1412-1439/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: /waitForPendingFutures
03-19 20:16:03.229 1412-1439/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:03.229 1412-1439/com.couchbase.lite.test E/Sync﹕ PullerInternal stopGraceful.run() finished
03-19 20:16:03.229 1412-1428/com.couchbase.lite.test I/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8 inserting 1 revisions...
03-19 20:16:03.229 1412-1428/com.couchbase.lite.test V/Database﹕ CBLManagerWorkExecutor Begin transaction (level 0)
03-19 20:16:03.229 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: inserting doc2 [1-563b]
03-19 20:16:03.229 1412-1428/com.couchbase.lite.test V/Database﹕ CBLManagerWorkExecutor Begin transaction (level 1)
03-19 20:16:03.269 1412-1428/com.couchbase.lite.test V/Database﹕ CBLManagerWorkExecutor Committing transaction (level 1)
03-19 20:16:03.269 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: finished inserting 1 revisions
03-19 20:16:03.269 1412-1428/com.couchbase.lite.test V/Database﹕ CBLManagerWorkExecutor Committing transaction (level 0)
03-19 20:16:03.289 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: Setting lastSequence to 2 from(null)
03-19 20:16:03.289 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: inserted 1 revs in 60 milliseconds
03-19 20:16:03.289 1412-1428/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8 insertDownloads() updating completedChangesCount from 0 -> 1
03-19 20:16:03.289 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: Incrementing completedChangesCount count from 0 by adding 1 -> 1
03-19 20:16:03.289 1412-1428/com.couchbase.lite.test V/CBLite﹕ setPaused: false
03-19 20:16:03.289 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:03.289 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:03.289 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => IDLE
03-19 20:16:03.289 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] IDLE => IDLE
03-19 20:16:03.289 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 1
03-19 20:16:03.289 1412-1438/com.couchbase.lite.test D/Batcher﹕ done calling future.get() on java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@b1ec72d8
03-19 20:16:03.289 1412-1438/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: /waitForPendingFutures
03-19 20:16:03.289 1412-1438/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:03.289 1412-1438/com.couchbase.lite.test E/Sync﹕ PullerInternal stopGraceful.run() finished
03-19 20:16:03.299 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:03.299 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:03.299 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => IDLE
03-19 20:16:03.299 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] IDLE => IDLE
03-19 20:16:08.289 1412-1428/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: saveLastSequence() called. lastSequence: 2 remoteCheckpoint: null
03-19 20:16:08.289 1412-1428/com.couchbase.lite.test I/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: start put remote _local document. checkpointID: e2d56953d893f93c61cbb2655639401ff3193065 body: {lastSequence=2}
03-19 20:16:08.299 1412-1428/com.couchbase.lite.test D/Sync﹕ [sendAsyncRequest()] PUT => http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.299 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry@b1e30298: RemoteRequestRetry created, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.309 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1e9ddf8: RemoteRequest created, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.309 1412-1440/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1e9ddf8: RemoteRequest run() called, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.319 1412-1428/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => RESUME
03-19 20:16:08.319 1412-1440/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1e9ddf8: RemoteRequest calling httpClient.execute, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.319 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: RESUME
03-19 20:16:08.329 1412-1445/com.couchbase.lite.test D/Sync﹕ calling future.get() on com.couchbase.lite.support.RemoteRequestRetry@b1e30298
03-19 20:16:08.329 1412-1440/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1e9ddf8: RemoteRequest calling httpClient.execute, client: org.apache.http.impl.client.DefaultHttpClient@b1e3af18 url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.329 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing RESUME
03-19 20:16:08.349 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => RUNNING
03-19 20:16:08.349 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: IDLE -> RUNNING (via RESUME). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:08.359 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 1
03-19 20:16:08.359 1412-1447/com.couchbase.lite.test I/System.out﹕ Request: PUT /db/_local/e2d56953d893f93c61cbb2655639401ff3193065 HTTP/1.1
03-19 20:16:08.379 1412-1447/com.couchbase.lite.test I/System.out﹕ Response: Buffer[size=78 md5=4d1f6577f99c7072a97e1575290bc6a9]
03-19 20:16:08.379 1412-1440/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1e9ddf8: RemoteRequest called httpClient.execute, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.399 1412-1440/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1e9ddf8: RemoteRequest finally block. url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.399 1412-1440/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1e9ddf8: RemoteRequest calling respondWithResult. url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065, error: null
03-19 20:16:08.399 1412-1440/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry$1@b1e7cb30: RemoteRequestRetry inner request finished, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.399 1412-1440/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.support.RemoteRequestRetry$1@b1e7cb30: RemoteRequestRetry was successful, calling callback url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.399 1412-1440/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.ReplicationInternal$7@b1e61b68: put remote _local document request finished. checkpointID: e2d56953d893f93c61cbb2655639401ff3193065 body: {lastSequence=2}
03-19 20:16:08.409 1412-1440/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.ReplicationInternal$7@b1e61b68: saved remote checkpoint, updating local checkpoint. remoteCheckpoint: {_rev=0-1, lastSequence=2}
03-19 20:16:08.409 1412-1440/com.couchbase.lite.test V/CBLite﹕ com.couchbase.lite.Database[/data/data/com.couchbase.lite.test/files/test/cblite-test.cblite]: setLastSequence() called with lastSequence: 2 checkpointId: e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.409 1412-1440/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.support.RemoteRequest@b1e9ddf8: RemoteRequest run() finished, url: http://localhost:40340/db/_local/e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:16:08.409 1412-1445/com.couchbase.lite.test D/Sync﹕ done calling future.get() on com.couchbase.lite.support.RemoteRequestRetry@b1e30298
03-19 20:16:08.409 1412-1445/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:08.419 1412-1447/com.couchbase.lite.test I/MockWebServer﹕ Received request: PUT /db/_local/e2d56953d893f93c61cbb2655639401ff3193065 HTTP/1.1 and responded: HTTP/1.1 201 OK
03-19 20:16:08.429 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:08.429 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:08.429 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] RUNNING => IDLE
03-19 20:16:08.429 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: RUNNING -> IDLE (via WAITING_FOR_CHANGES). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:08.429 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 1
03-19 20:16:11.659 1412-1428/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal$10@b1edf158 still running, restarting change tracker
03-19 20:16:11.659 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: starting ChangeTracker with since=2 mode=OneShot
03-19 20:16:11.659 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: started ChangeTracker com.couchbase.lite.replicator.ChangeTracker@b1e5d360
03-19 20:16:11.659 1412-1428/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e5d360: Changed tracker asked to start
03-19 20:16:11.659 1412-1448/com.couchbase.lite.test E/ChangeTracker﹕ Thread id => 114
03-19 20:16:11.669 1412-1448/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e5d360: Making request to http://localhost:40340/db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2
03-19 20:16:11.709 1412-1451/com.couchbase.lite.test D/dalvikvm﹕ GC_FOR_ALLOC freed 286K, 15% free 3927K/4588K, paused 19ms, total 20ms
03-19 20:16:11.719 1412-1451/com.couchbase.lite.test I/System.out﹕ Request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2 HTTP/1.1
03-19 20:16:11.739 1412-1448/com.couchbase.lite.test E/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e5d360: Change tracker got error 406
03-19 20:16:11.739 1412-1448/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e5d360: Change tracker run loop exiting
03-19 20:16:11.739 1412-1448/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e5d360: Change tracker in stopped()
03-19 20:16:11.739 1412-1448/com.couchbase.lite.test W/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e5d360: Change tracker calling changeTrackerStopped, client: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:11.749 1412-1428/com.couchbase.lite.test D/Sync﹕ changeTrackerStopped. lifecycle: CONTINUOUS
03-19 20:16:11.749 1412-1428/com.couchbase.lite.test E/Sync﹕ Change tracker stopped during continuous replication
03-19 20:16:11.749 1412-1428/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:11.749 1412-1428/com.couchbase.lite.test D/Sync﹕ Scheduling change tracker restart in 10000 ms
03-19 20:16:11.759 1412-1451/com.couchbase.lite.test I/MockWebServer﹕ Received request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2 HTTP/1.1 and responded: HTTP/1.1 406 NOT ACCEPTABLE
03-19 20:16:11.759 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:11.759 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:11.759 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => IDLE
03-19 20:16:11.759 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] IDLE => IDLE
03-19 20:16:21.759 1412-1428/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal$10@b1e96508 still running, restarting change tracker
03-19 20:16:21.759 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: starting ChangeTracker with since=2 mode=OneShot
03-19 20:16:21.759 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: started ChangeTracker com.couchbase.lite.replicator.ChangeTracker@b1ee69e8
03-19 20:16:21.759 1412-1428/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ee69e8: Changed tracker asked to start
03-19 20:16:21.769 1412-1452/com.couchbase.lite.test E/ChangeTracker﹕ Thread id => 117
03-19 20:16:21.779 1412-1452/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ee69e8: Making request to http://localhost:40340/db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2
03-19 20:16:21.799 1412-1447/com.couchbase.lite.test I/System.out﹕ Request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2 HTTP/1.1
03-19 20:16:21.799 1412-1452/com.couchbase.lite.test E/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ee69e8: Change tracker got error 406
03-19 20:16:21.809 1412-1447/com.couchbase.lite.test I/MockWebServer﹕ Received request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2 HTTP/1.1 and responded: HTTP/1.1 406 NOT ACCEPTABLE
03-19 20:16:21.809 1412-1452/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ee69e8: Change tracker run loop exiting
03-19 20:16:21.809 1412-1452/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ee69e8: Change tracker in stopped()
03-19 20:16:21.809 1412-1452/com.couchbase.lite.test W/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1ee69e8: Change tracker calling changeTrackerStopped, client: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:21.809 1412-1428/com.couchbase.lite.test D/Sync﹕ changeTrackerStopped. lifecycle: CONTINUOUS
03-19 20:16:21.809 1412-1428/com.couchbase.lite.test E/Sync﹕ Change tracker stopped during continuous replication
03-19 20:16:21.809 1412-1428/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:21.819 1412-1428/com.couchbase.lite.test D/Sync﹕ Scheduling change tracker restart in 10000 ms
03-19 20:16:21.819 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:21.819 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:21.819 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => IDLE
03-19 20:16:21.819 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] IDLE => IDLE
03-19 20:16:31.819 1412-1428/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal$10@b1e3d190 still running, restarting change tracker
03-19 20:16:31.819 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: starting ChangeTracker with since=2 mode=OneShot
03-19 20:16:31.819 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: started ChangeTracker com.couchbase.lite.replicator.ChangeTracker@b1e89508
03-19 20:16:31.829 1412-1428/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e89508: Changed tracker asked to start
03-19 20:16:31.829 1412-1455/com.couchbase.lite.test E/ChangeTracker﹕ Thread id => 119
03-19 20:16:31.839 1412-1455/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e89508: Making request to http://localhost:40340/db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2
03-19 20:16:31.859 1412-1432/com.couchbase.lite.test I/System.out﹕ Request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2 HTTP/1.1
03-19 20:16:31.859 1412-1455/com.couchbase.lite.test E/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e89508: Change tracker got error 406
03-19 20:16:31.859 1412-1455/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e89508: Change tracker run loop exiting
03-19 20:16:31.869 1412-1455/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e89508: Change tracker in stopped()
03-19 20:16:31.869 1412-1455/com.couchbase.lite.test W/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e89508: Change tracker calling changeTrackerStopped, client: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:31.869 1412-1428/com.couchbase.lite.test D/Sync﹕ changeTrackerStopped. lifecycle: CONTINUOUS
03-19 20:16:31.869 1412-1428/com.couchbase.lite.test E/Sync﹕ Change tracker stopped during continuous replication
03-19 20:16:31.869 1412-1428/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:31.869 1412-1428/com.couchbase.lite.test D/Sync﹕ Scheduling change tracker restart in 10000 ms
03-19 20:16:31.869 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:31.879 1412-1432/com.couchbase.lite.test I/MockWebServer﹕ Received request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2 HTTP/1.1 and responded: HTTP/1.1 406 NOT ACCEPTABLE
03-19 20:16:31.879 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:31.879 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => IDLE
03-19 20:16:31.879 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] IDLE => IDLE
03-19 20:16:41.879 1412-1428/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal$10@b1ed45f0 still running, restarting change tracker
03-19 20:16:41.879 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: starting ChangeTracker with since=2 mode=OneShot
03-19 20:16:41.879 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: started ChangeTracker com.couchbase.lite.replicator.ChangeTracker@b1e392a0
03-19 20:16:41.879 1412-1428/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e392a0: Changed tracker asked to start
03-19 20:16:41.889 1412-1462/com.couchbase.lite.test E/ChangeTracker﹕ Thread id => 121
03-19 20:16:41.889 1412-1462/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e392a0: Making request to http://localhost:40340/db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2
03-19 20:16:41.909 1412-1437/com.couchbase.lite.test I/System.out﹕ Request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2 HTTP/1.1
03-19 20:16:41.919 1412-1462/com.couchbase.lite.test E/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e392a0: Change tracker got error 406
03-19 20:16:41.919 1412-1462/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e392a0: Change tracker run loop exiting
03-19 20:16:41.919 1412-1462/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e392a0: Change tracker in stopped()
03-19 20:16:41.919 1412-1462/com.couchbase.lite.test W/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1e392a0: Change tracker calling changeTrackerStopped, client: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:41.929 1412-1428/com.couchbase.lite.test D/Sync﹕ changeTrackerStopped. lifecycle: CONTINUOUS
03-19 20:16:41.929 1412-1428/com.couchbase.lite.test E/Sync﹕ Change tracker stopped during continuous replication
03-19 20:16:41.929 1412-1428/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:41.929 1412-1428/com.couchbase.lite.test D/Sync﹕ Scheduling change tracker restart in 10000 ms
03-19 20:16:41.939 1412-1437/com.couchbase.lite.test I/MockWebServer﹕ Received request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2 HTTP/1.1 and responded: HTTP/1.1 406 NOT ACCEPTABLE
03-19 20:16:41.939 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:41.949 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:41.959 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => IDLE
03-19 20:16:41.959 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] IDLE => IDLE
03-19 20:16:51.939 1412-1428/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal$10@b1e366d8 still running, restarting change tracker
03-19 20:16:51.939 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: starting ChangeTracker with since=2 mode=OneShot
03-19 20:16:51.939 1412-1428/com.couchbase.lite.test W/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: started ChangeTracker com.couchbase.lite.replicator.ChangeTracker@b1f172c8
03-19 20:16:51.939 1412-1428/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1f172c8: Changed tracker asked to start
03-19 20:16:51.949 1412-1465/com.couchbase.lite.test E/ChangeTracker﹕ Thread id => 123
03-19 20:16:51.949 1412-1465/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1f172c8: Making request to http://localhost:40340/db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2
03-19 20:16:51.979 1412-1468/com.couchbase.lite.test I/System.out﹕ Request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2 HTTP/1.1
03-19 20:16:51.989 1412-1468/com.couchbase.lite.test I/MockWebServer﹕ Received request: GET /db/_changes?feed=normal&heartbeat=300000&style=all_docs&since=2 HTTP/1.1 and responded: HTTP/1.1 406 NOT ACCEPTABLE
03-19 20:16:51.999 1412-1465/com.couchbase.lite.test E/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1f172c8: Change tracker got error 406
03-19 20:16:51.999 1412-1465/com.couchbase.lite.test V/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1f172c8: Change tracker run loop exiting
03-19 20:16:52.009 1412-1465/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1f172c8: Change tracker in stopped()
03-19 20:16:52.009 1412-1465/com.couchbase.lite.test W/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1f172c8: Change tracker calling changeTrackerStopped, client: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:16:52.009 1412-1428/com.couchbase.lite.test D/Sync﹕ changeTrackerStopped. lifecycle: CONTINUOUS
03-19 20:16:52.019 1412-1428/com.couchbase.lite.test E/Sync﹕ Change tracker stopped during continuous replication
03-19 20:16:52.019 1412-1428/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => WAITING_FOR_CHANGES
03-19 20:16:52.019 1412-1428/com.couchbase.lite.test D/Sync﹕ Scheduling change tracker restart in 10000 ms
03-19 20:16:52.019 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: WAITING_FOR_CHANGES
03-19 20:16:52.019 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing WAITING_FOR_CHANGES
03-19 20:16:52.019 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => IDLE
03-19 20:16:52.019 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] IDLE => IDLE
03-19 20:17:01.429 1412-1425/com.couchbase.lite.test V/LiteTestCase﹕ tearDown
03-19 20:17:01.429 1412-1425/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => STOP_GRACEFUL
03-19 20:17:01.429 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: STOP_GRACEFUL
03-19 20:17:01.429 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing STOP_GRACEFUL
03-19 20:17:01.439 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => STOPPING
03-19 20:17:01.449 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: IDLE -> STOPPING (via STOP_GRACEFUL). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:17:01.449 1412-1428/com.couchbase.lite.test V/Sync﹕ [onExit()] IDLE => STOPPING
03-19 20:17:01.449 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] IDLE => STOPPING
03-19 20:17:01.459 1412-1428/com.couchbase.lite.test D/Sync﹕ stopGraceful()
03-19 20:17:01.459 1412-1428/com.couchbase.lite.test D/Sync﹕ PullerInternal stopGraceful()
03-19 20:17:01.459 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: IDLE -> STOPPING (via STOP_GRACEFUL). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:17:01.469 1412-1469/com.couchbase.lite.test D/Sync﹕ batcher.waitForPendingFutures()
03-19 20:17:01.479 1412-1469/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: waitForPendingFutures
03-19 20:17:01.479 1412-1469/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed8588: /waitForPendingFutures
03-19 20:17:01.479 1412-1469/com.couchbase.lite.test D/Sync﹕ waitForPendingFutures()
03-19 20:17:01.479 1412-1469/com.couchbase.lite.test D/Sync﹕ downloadsToInsert.waitForPendingFutures()
03-19 20:17:01.479 1412-1469/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: waitForPendingFutures
03-19 20:17:01.489 1412-1469/com.couchbase.lite.test D/Batcher﹕ com.couchbase.lite.support.Batcher@b1ed1dc0: /waitForPendingFutures
03-19 20:17:01.489 1412-1469/com.couchbase.lite.test D/Sync﹕ stopping change tracker
03-19 20:17:01.489 1412-1469/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1f172c8: Changed tracker asked to stop
03-19 20:17:01.489 1412-1469/com.couchbase.lite.test D/ChangeTracker﹕ com.couchbase.lite.replicator.ChangeTracker@b1f172c8: Changed tracker aborting request: org.apache.http.client.methods.HttpGet@b1ecea98
03-19 20:17:01.509 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 1
03-19 20:17:01.509 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 1
03-19 20:17:01.509 1412-1469/com.couchbase.lite.test D/Sync﹕ stopped change tracker
03-19 20:17:01.519 1412-1469/com.couchbase.lite.test W/Sync﹕ [fireTrigger()] => STOP_IMMEDIATE
03-19 20:17:01.519 1412-1428/com.couchbase.lite.test D/Sync﹕ firing trigger: STOP_IMMEDIATE
03-19 20:17:01.519 1412-1428/com.couchbase.lite.test I/StateMachine﹕ Firing STOP_IMMEDIATE
03-19 20:17:01.529 1412-1428/com.couchbase.lite.test V/Sync﹕ [onEntry()] STOPPING => STOPPED
03-19 20:17:01.529 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: clearDbRef() called
03-19 20:17:01.529 1412-1428/com.couchbase.lite.test V/CBLite﹕ com.couchbase.lite.Database[/data/data/com.couchbase.lite.test/files/test/cblite-test.cblite]: setLastSequence() called with lastSequence: 2 checkpointId: e2d56953d893f93c61cbb2655639401ff3193065
03-19 20:17:01.539 1412-1469/com.couchbase.lite.test E/Sync﹕ PullerInternal stopGraceful.run() finished
03-19 20:17:01.549 1412-1428/com.couchbase.lite.test V/Sync﹕ com.couchbase.lite.replicator.PullerInternal@b1eef4f8: clearDbRef() setting db to null
03-19 20:17:01.559 1412-1428/com.couchbase.lite.test D/Sync﹕ State transition: STOPPING -> STOPPED (via STOP_IMMEDIATE). this: com.couchbase.lite.replicator.PullerInternal@b1eef4f8
03-19 20:17:01.559 1412-1428/com.couchbase.lite.test E/Sync﹕ event.getCompletedChangeCount() = 1
03-19 20:17:01.569 1412-1425/com.couchbase.lite.test V/Database﹕ AndroidSQLiteStorageEngine{database=b1e22bc8}: Closed Android sqlite db
03-19 20:17:01.569 1412-1425/com.couchbase.lite.test I/CBLite﹕ Closing com.couchbase.lite.Manager@b1e2b530
03-19 20:17:02.019 1412-1428/com.couchbase.lite.test D/Sync﹕ com.couchbase.lite.replicator.PullerInternal$10@b1ef4418 still no longer running, not restarting change tracker
03-19 20:17:02.019 1412-1425/com.couchbase.lite.test I/CBLite﹕ Closed com.couchbase.lite.Manager@b1e2b530
03-19 20:17:02.029 1412-1425/com.couchbase.lite.test I/TestRunner﹕ failed: testGoOffline(com.couchbase.lite.replicator.ReplicationTest)
03-19 20:17:02.029 1412-1425/com.couchbase.lite.test I/TestRunner﹕ ----- begin exception -----
03-19 20:17:02.039 1412-1425/com.couchbase.lite.test I/TestRunner﹕ junit.framework.AssertionFailedError
at junit.framework.Assert.fail(Assert.java:48)
at junit.framework.Assert.assertTrue(Assert.java:20)
at junit.framework.Assert.assertTrue(Assert.java:27)
at com.couchbase.lite.replicator.ReplicationTest.testGoOffline(ReplicationTest.java:2630)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:515)
at junit.framework.TestCase.runTest(TestCase.java:168)
at junit.framework.TestCase.runBare(TestCase.java:134)
at junit.framework.TestResult$1.protect(TestResult.java:115)
at junit.framework.TestResult.runProtected(TestResult.java:133)
at junit.framework.TestResult.run(TestResult.java:118)
at junit.framework.TestCase.run(TestCase.java:124)
at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:191)
at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:176)
at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:554)
at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1701)
03-19 20:17:02.039 1412-1425/com.couchbase.lite.test I/TestRunner﹕ ----- end exception -----
03-19 20:17:02.099 1412-1425/com.couchbase.lite.test D/dalvikvm﹕ GC_FOR_ALLOC freed 568K, 19% free 3873K/4724K, paused 19ms, total 21ms
03-19 20:17:02.119 1412-1425/com.couchbase.lite.test I/TestRunner﹕ finished: testGoOffline(com.couchbase.lite.replicator.ReplicationTest)
03-19 20:17:02.149 1402-1402/? D/AndroidRuntime﹕ Shutting down VM
03-19 20:17:02.169 1402-1408/? D/dalvikvm﹕ Debugger has detached; object registry had 1 entries
03-19 20:17:02.429 378-756/system_process I/ActivityManager﹕ Force stopping com.couchbase.lite.test appid=10052 user=0: finished inst
03-19 20:17:02.429 378-756/system_process I/ActivityManager﹕ Killing 1412:com.couchbase.lite.test/u0a52 (adj 0): stop com.couchbase.lite.test
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment