Push replication in background.

[Martin Palatnik]

Hi, 

In an app I'm working on I'm using Region monitoring and couchbase. When I enter the region, I need to save some information to the database and that info needs to be synced to the server ( I have a continuous push replication running) while running the app in the background. I'm setting suspended to NO to tell couchbase to perform the saving and syncing in the background.

I have an important constraint: When the region is detected I have around 10 secs to perform that, otherwise I can request more time with beginBackgroundTaskWithExpirationHandler: as mentioned in Apple documentation. 

"In iOS, regions associated with your app are tracked at all times, including when the app isn’t running. If a region boundary is crossed while an app isn’t running, that app is relaunched into the background to handle the event. Similarly, if the app is suspended when the event occurs, it’s woken up and given a short amount of time (around 10 seconds) to handle the event. When necessary, an app can request more background execution time using the beginBackgroundTaskWithExpirationHandler: method of the UIApplication class."

In 3G conditions I found that the 10 secs are often not enough to perform the saving and sync to the remote server, so I need to use some extra time by using beginBackgroundTaskWithExpirationHandler:.  

The problem I'm having is that the synchronization dies anyway after the 10 secs even if I use beginBackgroundTaskWithExpirationHandler:. My hint is that the syncing is probably executing in a different thread and iOS kills it anyway after the 10 secs not taking into account the backgroundtask. 

Any ideas?

Thanks, 

Martin

PS: Thanks for such a great work with couchbase. Below are links to two apps already in the store and google play that I did using couchbase lite. 

https://itunes.apple.com/en/app/puntatech/id955333100?mt=8

https://play.google.com/store/apps/details?id=com.nearup.puntatech.android

https://itunes.apple.com/us/app/mvdvalley/id932392599?mt=8

https://play.google.com/store/apps/details?id=com.nearup.android

[Traun Leyden]

This issue might be relevant:

https://github.com/tleyden/office-radar/issues/1#issuecomment-48780693

--
You received this message because you are subscribed to the Google Groups "Couchbase Mobile" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mobile-couchba...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/mobile-couchbase/045fc314-6d6e-4d72-a267-f54e748a0eca%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Jens Alfke]

On Jan 19, 2015, at 1:06 PM, Martin Palatnik <mar...@gmail.com> wrote:

The problem I'm having is that the synchronization dies anyway after the 10 secs even if I use beginBackgroundTaskWithExpirationHandler:. My hint is that the syncing is probably executing in a different thread and iOS kills it anyway after the 10 secs not taking into account the background task. 

I don't think it matters what thread things are running on. They're all in a single process (your app). The OS won't kill individual threads; that's only something code running inside your process would do, and even then it's considered a very bad idea to kill a thread without its consent.

Can you provide more info? Like, how do you know the synchronization dies? Does the rest of your process exit at the same time?

—Jens

[Martin Palatnik]

@Traun, yes it's probably related though I think in that example you never set the suspended to NO and you don't use background task to request more time. 

@Jens, I was suggesting that it had something to do with threads because the thread where the background task is executing keeps on running (but just hint). 

Below is a detailed log of couchbase. After 60 sec I call a timer to finish the background task and set the suspended to YES. As you will see the CBL_Pusher is never executing. Couchbase stops doing things after 10 secs. The timer also in the background is called after 60 secs. 

-----

2015-01-20 11:52:38.966 PuntaTech[942:390809] Entered region: ESTBeaconRegion: B9407F30-F5F8-466E-AFF9-25556B57FE6D : 13303 : 0

2015-01-20 11:52:39.125 PuntaTech[942:390809] Sync: CBLReplication[from http://104.131.164.61:8080/nearup]: active, progress = 15 / 15, err: (null)

2015-01-20 11:52:39.127 PuntaTech[942:390809] SYNCMGR: active=1; status=3; 15/15; (null)

2015-01-20 11:52:40.682 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[GET http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Got response, status 200

2015-01-20 11:52:40.687 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[GET http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Finished loading

2015-01-20 11:52:40.690 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup]: Replicating from lastSequence=51

2015-01-20 11:52:40.691 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup] starting ChangeTracker: mode=3, since=51

2015-01-20 11:52:40.693 PuntaTech[942:391055] SyncVerbose: CBLWebSocketChangeTracker[0x170179080 nearup]: GET //104.131.164.61:8080/nearup/_changes?feed=websocket

2015-01-20 11:52:41.592 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (15/16, active=1 (batch=0, net=1), online=1)

2015-01-20 11:52:41.593 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: Received #81 {u:avEhFiUL_H #43-e0c4ea1e46274f3fa98b898a9ef0bf5c}

2015-01-20 11:52:41.597 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup]: Caught up with changes!

2015-01-20 11:52:41.597 PuntaTech[942:390809] Sync: CBLReplication[from http://104.131.164.61:8080/nearup]: active, progress = 15 / 16, err: (null)

2015-01-20 11:52:41.598 PuntaTech[942:391055] SyncVerbose: *** CBL_Puller[http://104.131.164.61:8080/nearup]: BEGIN processInbox (1 sequences)

2015-01-20 11:52:41.599 PuntaTech[942:390809] SYNCMGR: active=1; status=3; 15/16; (null)

2015-01-20 11:52:41.601 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: Looking up (

    "{u:avEhFiUL_H #43-e0c4ea1e46274f3fa98b898a9ef0bf5c}"

)

2015-01-20 11:52:41.604 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] Progress: 16 / 16

2015-01-20 11:52:41.605 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (16/16, active=1 (batch=0, net=0), online=1)

2015-01-20 11:52:41.606 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: no new remote revisions to fetch

2015-01-20 11:52:41.607 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: Setting lastSequence to 81 (from 51)

2015-01-20 11:52:41.608 PuntaTech[942:391055] SyncVerbose: *** CBL_Puller[http://104.131.164.61:8080/nearup]: END processInbox (lastSequence=81)

2015-01-20 11:52:41.609 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] Progress: set active = 0

2015-01-20 11:52:41.609 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (16/16, active=0 (batch=0, net=0), online=1)

2015-01-20 11:52:41.611 PuntaTech[942:390809] Sync: CBLReplication[from http://104.131.164.61:8080/nearup]: idle, progress = 16 / 16, err: (null)

2015-01-20 11:52:41.611 PuntaTech[942:390809] SYNCMGR: active=0; status=2; 0/0; (null)

2015-01-20 11:52:46.715 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] checkpointing sequence=81

2015-01-20 11:52:46.716 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: PUT _local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d

2015-01-20 11:52:46.719 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[PUT http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Starting...

2015-01-20 11:52:48.115 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[PUT http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Got response, status 201

2015-01-20 11:52:48.116 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[PUT http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Finished loading

2015-01-20 11:52:48.155 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] saved remote checkpoint '81' (_rev=0-2)

2015-01-20 11:53:39.176 PuntaTech[942:390809] Timer executed

2015-01-20 11:53:39.179 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup]: Reachability state = <104.131.164.61>:reachable (3G) (40003), suspended=1

2015-01-20 11:53:39.184 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup]: Going offline

------

Below is the logs when you go back to foreground and the Pusher is executed. 

------

2015-01-20 11:56:59.463 PuntaTech[942:391055] Sync: Stopping 0 remote requests

2015-01-20 11:56:59.463 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (16/16, active=0 (batch=0, net=0), online=0)

2015-01-20 11:56:59.463 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup]: ChangeTracker stopped; error=(null)

2015-01-20 11:56:59.556 PuntaTech[942:390809] APP FOREGROUNDING

2015-01-20 11:56:59.557 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup]: Reachability state = <104.131.164.61>:reachable (3G) (40003), suspended=0

2015-01-20 11:56:59.557 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup]: Going online

2015-01-20 11:56:59.558 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] Progress: set active = 1

2015-01-20 11:56:59.558 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (16/16, active=1 (batch=0, net=1), online=1)

2015-01-20 11:56:59.558 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: GET _local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d

2015-01-20 11:56:59.559 PuntaTech[942:390809] APP FOREGROUNDING

2015-01-20 11:56:59.559 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[GET http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Starting...

2015-01-20 11:56:59.560 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (16/16, active=1 (batch=0, net=1), online=1)

2015-01-20 11:56:59.561 PuntaTech[942:391055] Sync: CBL_Pusher[http://104.131.164.61:8080/nearup]: Reachability state = <104.131.164.61>:reachable (3G) (40003), suspended=0

2015-01-20 11:56:59.562 PuntaTech[942:391055] Sync: CBL_Pusher[http://104.131.164.61:8080/nearup]: Going online

2015-01-20 11:56:59.563 PuntaTech[942:391055] Sync: CBL_Pusher[http://104.131.164.61:8080/nearup] Progress: set active = 1

2015-01-20 11:56:59.563 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: postProgressChanged (0/0, active=1 (batch=0, net=1), online=1)

2015-01-20 11:56:59.564 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: GET _local/015caeb8c62d91ac9fc25128ac804426d000e53b

2015-01-20 11:56:59.564 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[GET http://104.131.164.61:8080/nearup/_local/015caeb8c62d91ac9fc25128ac804426d000e53b]: Starting...

2015-01-20 11:56:59.564 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: postProgressChanged (0/0, active=1 (batch=0, net=1), online=1)

2015-01-20 11:56:59.568 PuntaTech[942:390809] Sync: CBLReplication[from http://104.131.164.61:8080/nearup]: offline, progress = 16 / 16, err: (null)

2015-01-20 11:56:59.569 PuntaTech[942:390809] SYNCMGR: active=0; status=1; 0/0; (null)

2015-01-20 11:56:59.569 PuntaTech[942:390809] Sync: CBLReplication[from http://104.131.164.61:8080/nearup]: active, progress = 16 / 16, err: (null)

2015-01-20 11:56:59.569 PuntaTech[942:390809] SYNCMGR: active=1; status=3; 16/16; (null)

2015-01-20 11:56:59.569 PuntaTech[942:390809] Sync: CBLReplication[to http://104.131.164.61:8080/nearup]: active, progress = 0 / 0, err: (null)

2015-01-20 11:57:01.030 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[GET http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Got response, status 200

2015-01-20 11:57:01.031 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[GET http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Finished loading

2015-01-20 11:57:01.031 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup]: Replicating from lastSequence=81

2015-01-20 11:57:01.032 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup] starting ChangeTracker: mode=3, since=81

2015-01-20 11:57:01.032 PuntaTech[942:391055] SyncVerbose: CBLWebSocketChangeTracker[0x170176140 nearup]: GET //104.131.164.61:8080/nearup/_changes?feed=websocket

2015-01-20 11:57:01.076 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[GET http://104.131.164.61:8080/nearup/_local/015caeb8c62d91ac9fc25128ac804426d000e53b]: Got response, status 200

2015-01-20 11:57:01.077 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[GET http://104.131.164.61:8080/nearup/_local/015caeb8c62d91ac9fc25128ac804426d000e53b]: Finished loading

2015-01-20 11:57:01.078 PuntaTech[942:391055] Sync: CBL_Pusher[http://104.131.164.61:8080/nearup]: Replicating from lastSequence=69

2015-01-20 11:57:01.079 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: Received 6 revs

2015-01-20 11:57:01.079 PuntaTech[942:391055] SyncVerbose: *** CBL_Pusher[http://104.131.164.61:8080/nearup]: BEGIN processInbox (6 sequences)

2015-01-20 11:57:01.080 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: POST _revs_diff

2015-01-20 11:57:01.080 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[POST http://104.131.164.61:8080/nearup/_revs_diff]: Starting...

2015-01-20 11:57:01.081 PuntaTech[942:391055] SyncVerbose: *** CBL_Pusher[http://104.131.164.61:8080/nearup]: END processInbox (lastSequence=69)

2015-01-20 11:57:01.640 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[POST http://104.131.164.61:8080/nearup/_revs_diff]: Got response, status 200

2015-01-20 11:57:01.641 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[POST http://104.131.164.61:8080/nearup/_revs_diff]: Finished loading

2015-01-20 11:57:01.643 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: Setting lastSequence to 71 (from 69)

2015-01-20 11:57:01.643 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: Setting lastSequence to 72 (from 71)

2015-01-20 11:57:01.644 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: Setting lastSequence to 74 (from 72)

2015-01-20 11:57:01.647 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: Setting lastSequence to 75 (from 74)

2015-01-20 11:57:01.648 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: Setting lastSequence to 76 (from 75)

2015-01-20 11:57:01.660 PuntaTech[942:391055] SyncVerbose: Stubbed out attachment {u:avEhFiUL_H #44-f5ce00678402a8ee27557c66723a9124}/'image': revpos 2 < 44

2015-01-20 11:57:01.662 PuntaTech[942:391055] Sync: CBL_Pusher[http://104.131.164.61:8080/nearup]: Sending 1 revisions

2015-01-20 11:57:01.663 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: Sending (

    "{u:avEhFiUL_H #44-f5ce00678402a8ee27557c66723a9124}"

)

2015-01-20 11:57:01.663 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: postProgressChanged (0/1, active=1 (batch=0, net=1), online=1)

2015-01-20 11:57:01.664 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: POST _bulk_docs

2015-01-20 11:57:01.669 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[POST http://104.131.164.61:8080/nearup/_bulk_docs]: Starting...

2015-01-20 11:57:01.671 PuntaTech[942:390809] Sync: CBLReplication[to http://104.131.164.61:8080/nearup]: active, progress = 0 / 1, err: (null)

2015-01-20 11:57:01.672 PuntaTech[942:390809] SYNCMGR: active=1; status=3; 16/17; (null)

2015-01-20 11:57:01.795 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup]: Caught up with changes!

2015-01-20 11:57:01.796 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] Progress: set active = 0

2015-01-20 11:57:01.796 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (16/16, active=0 (batch=0, net=0), online=1)

2015-01-20 11:57:01.798 PuntaTech[942:390809] Sync: CBLReplication[from http://104.131.164.61:8080/nearup]: idle, progress = 16 / 16, err: (null)

2015-01-20 11:57:01.798 PuntaTech[942:390809] SYNCMGR: active=1; status=3; 0/1; (null)

2015-01-20 11:57:02.181 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[POST http://104.131.164.61:8080/nearup/_bulk_docs]: Got response, status 201

2015-01-20 11:57:02.182 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[POST http://104.131.164.61:8080/nearup/_bulk_docs]: Finished loading

2015-01-20 11:57:02.183 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: Setting lastSequence to 77 (from 76)

2015-01-20 11:57:02.184 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: Sent (

    "{u:avEhFiUL_H #44-f5ce00678402a8ee27557c66723a9124}"

)

2015-01-20 11:57:02.186 PuntaTech[942:391055] Sync: CBL_Pusher[http://104.131.164.61:8080/nearup] Progress: 1 / 1

2015-01-20 11:57:02.188 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: postProgressChanged (1/1, active=1 (batch=0, net=1), online=1)

2015-01-20 11:57:02.189 PuntaTech[942:391055] Sync: CBL_Pusher[http://104.131.164.61:8080/nearup] Progress: set active = 0

2015-01-20 11:57:02.189 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: postProgressChanged (1/1, active=0 (batch=0, net=0), online=1)

2015-01-20 11:57:02.190 PuntaTech[942:390809] Sync: CBLReplication[to http://104.131.164.61:8080/nearup]: idle, progress = 1 / 1, err: (null)

2015-01-20 11:57:02.191 PuntaTech[942:390809] SYNCMGR: active=0; status=2; 0/0; (null)

2015-01-20 11:57:02.843 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (16/17, active=0 (batch=0, net=0), online=1)

2015-01-20 11:57:02.844 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: Received #83 {u:avEhFiUL_H #44-f5ce00678402a8ee27557c66723a9124}

2015-01-20 11:57:02.845 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] Progress: set active = 1

2015-01-20 11:57:02.846 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (16/17, active=1 (batch=1, net=0), online=1)

2015-01-20 11:57:02.847 PuntaTech[942:390809] Sync: CBLReplication[from http://104.131.164.61:8080/nearup]: active, progress = 16 / 17, err: (null)

2015-01-20 11:57:02.847 PuntaTech[942:391055] SyncVerbose: *** CBL_Puller[http://104.131.164.61:8080/nearup]: BEGIN processInbox (1 sequences)

2015-01-20 11:57:02.848 PuntaTech[942:390809] SYNCMGR: active=1; status=3; 16/17; (null)

2015-01-20 11:57:02.848 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: Looking up (

    "{u:avEhFiUL_H #44-f5ce00678402a8ee27557c66723a9124}"

)

2015-01-20 11:57:02.852 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] Progress: 17 / 17

2015-01-20 11:57:02.853 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (17/17, active=1 (batch=0, net=0), online=1)

2015-01-20 11:57:02.854 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: no new remote revisions to fetch

2015-01-20 11:57:02.854 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: Setting lastSequence to 83 (from 81)

2015-01-20 11:57:02.855 PuntaTech[942:391055] SyncVerbose: *** CBL_Puller[http://104.131.164.61:8080/nearup]: END processInbox (lastSequence=83)

2015-01-20 11:57:02.856 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] Progress: set active = 0

2015-01-20 11:57:02.857 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: postProgressChanged (17/17, active=0 (batch=0, net=0), online=1)

2015-01-20 11:57:02.858 PuntaTech[942:390809] Sync: CBLReplication[from http://104.131.164.61:8080/nearup]: idle, progress = 17 / 17, err: (null)

2015-01-20 11:57:02.858 PuntaTech[942:390809] SYNCMGR: active=0; status=2; 0/0; (null)

2015-01-20 11:57:06.649 PuntaTech[942:391055] Sync: CBL_Pusher[http://104.131.164.61:8080/nearup] checkpointing sequence=77

2015-01-20 11:57:06.649 PuntaTech[942:391055] SyncVerbose: CBL_Pusher[http://104.131.164.61:8080/nearup]: PUT _local/015caeb8c62d91ac9fc25128ac804426d000e53b

2015-01-20 11:57:06.651 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[PUT http://104.131.164.61:8080/nearup/_local/015caeb8c62d91ac9fc25128ac804426d000e53b]: Starting...

2015-01-20 11:57:07.331 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[PUT http://104.131.164.61:8080/nearup/_local/015caeb8c62d91ac9fc25128ac804426d000e53b]: Got response, status 201

2015-01-20 11:57:07.332 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[PUT http://104.131.164.61:8080/nearup/_local/015caeb8c62d91ac9fc25128ac804426d000e53b]: Finished loading

2015-01-20 11:57:07.350 PuntaTech[942:391055] Sync: CBL_Pusher[http://104.131.164.61:8080/nearup] saved remote checkpoint '77' (_rev=0-2)

2015-01-20 11:57:07.860 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] checkpointing sequence=83

2015-01-20 11:57:07.861 PuntaTech[942:391055] SyncVerbose: CBL_Puller[http://104.131.164.61:8080/nearup]: PUT _local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d

2015-01-20 11:57:07.862 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[PUT http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Starting...

2015-01-20 11:57:08.468 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[PUT http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Got response, status 201

2015-01-20 11:57:08.469 PuntaTech[942:391055] RemoteRequest: CBLRemoteJSONRequest[PUT http://104.131.164.61:8080/nearup/_local/8e5b75dd689969ef0b1526cc963a8b3a1cebb00d]: Finished loading

2015-01-20 11:57:08.487 PuntaTech[942:391055] Sync: CBL_Puller[http://104.131.164.61:8080/nearup] saved remote checkpoint '83' (_rev=0-3)

------

What extra info can I provide to help you picture it? Any ideas on how to solve this?

[Jens Alfke]

On Jan 20, 2015, at 8:10 AM, Martin Palatnik <mar...@gmail.com> wrote:

Below is a detailed log of couchbase. After 60 sec I call a timer to finish the background task and set the suspended to YES. As you will see the CBL_Pusher is never executing. Couchbase stops doing things after 10 secs. The timer also in the background is called after 60 secs. 

I don't see any sign of a push replication in the logs, although the pull replicator runs normally. So the problem is either that there's no push replication, or there was no change made to the local database to trigger it to do anything.

This doesn't have anything to do with threads or the OS's background task timer, because both push and pull replications run on the same thread. So since the pull replication is doing stuff, the thread is alive and well.

—Jens

[Martin Palatnik]

There is a CBLModel save: executed on the local database while in the background. 

As you see in the second Log (from when the app goes to foreground), when the app goes to foreground the Pusher is executed to perform that operation that was scheduled in the background. 

I'm not saying the thread is dead, but for some reason some stuff the operation are not executed in the background when using  beginBackgroundTaskWithExpirationHandler: and I think is my have something to do with threading in that those operations run on a different thread than the thread calling beginBackgroundTaskWithExpirationHandler:.  But again, that is just a hint that I cannot probe yet. 

[Jens Alfke]

I am 99% confident this doesn't have anything to do with threads; that's just not how the OS app suspend/resume works. It suspends the entire process at once. (Trying to suspend individual threads is a guaranteed recipe for deadlock.)

It looks to me as though your push replication is still suspended until the app returns to the foreground, although I can't tell for sure from the logs you posted. I'd need to see the logs from before the app was backgrounded. Could you post a longer session? (But not directly to the list; put it in a Gist or something like that.)

—Jens

[Martin Palatnik]

I'll send you the gust with that. What I find weird is the timer is called after 60 secs, so the process is still running, and if I spin on a loop it will run also. 

[Martin Palatnik]

@Jens

https://gist.github.com/marpal/4a7c33c19827989773b7

The link to the longer session. What I happens in this session:

1) I leave the region in the background

2) The systems calls the callback didExitRegion, you can see the logging "Left region" and "User saved". However CBL logging for the queueing is never executed and the Pusher neither.

3) I bring app to foreground while outside the region, then CBL Push my changes to the user, you will the the Pusher active. 

4) I enter the region in foreground.

5) The system calls the callback didEnterRegion, you can see the logging "Entered region" and "User saved". The difference is that while in foreground CBL logs "Queuing #85 {u:avEhFiUL_H #52-2feddb87edc85561009aefb8e5084033}"

6) Pusher is executed inmediatelly.

Is like if the notification for the change in the database is not received when in the background and then the Pusher not triggered.

[Jens Alfke]

From the logs:

At 15:09:21.495 the puller gets suspended and goes offline (see "suspended=1" in the log.)

At 15:09:21.500 the pusher gets suspended and goes offline

At 15:09:59.157 the puller gets un-suspended and goes online.

…but there's never any corresponding message that the pusher got un-suspended, until the app is foregrounded.

So it looks like the problem is that only the pull replication is being un-suspended while you're doing stuff in the background. Check that you're un-suspending both your CBLReplications.

—Jens

[Martin Palatnik]

Right!!

Typical and stupid blame the compiler kind of bug. 

Thanks.