testGoOffline() failure Log

gistfile1.txt

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