Invalid callback id received by sendPluginResult

[rwillett]

We upgraded to PushWoosh 6.2.1 a few weeks ago and are still testing the upgrade.

We appear to be getting

Invalid callback id received by sendPluginResult

at the start of our app from PushWoosh. This is only occurring once every 10-15 times.

Since the app crashes its difficult to debug it further.

The error message we get is

2016-10-06 07:52:31.874 Jambuster[24572:2721034] [PW] [I] __57-[PWPushNotificationsManagerCommon sendDevTokenToServer:]_block_invoke Registered for push notifications: <<LONG STRING REMOVED>>
2016-10-06 07:52:31.877 Jambuster[24572:2721034] Invalid callback id received by sendPluginResult
2016-10-06 07:52:32.984 Jambuster[24572:2721034] Finished load of: file:///private/var/mobile/Containers/Bundle/Application/28C6229F-686B-4B7F-A9CB-B881FEA54C34/Jambuster.app/www/index.html#/tab/summary
2016-10-06 07:52:33.249 Jambuster[24572:2721034] [PW] [I] -[PWPushNotificationsManagerCommon sendDevTokenToServer:] Registered for push notifications: <<SAME LONG STRING REMOVED>>
2016-10-06 07:52:33.310 Jambuster[24572:2721034] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 

When the app starts up correctly, we don't get the

Invalid callback id received by sendPluginResult

We're struggling to work out what to do here as we never even get the deviceReady event (or $ionicPlatform.ready in our case). Its difficult to do anything.

Its definitely intermittent as we can start the app again and it will work.

Google has not helped here.

Any advice welcomed,

Thanks

Rob

[rwillett]

We have looked at this for the last few days and aren't getting much further. The issue appears to be in PushWoosh before anything happens on our side, i.e. before the deviceReady event is fired off.

This means we can't change any of our logic in our app as we never even reach our code.

We're struggling as to understand it, as the error is generic and only happens every so often. We start our app, it hangs with this error, we kill the app, start again and it will work for the next 10-15 starts and then die again. There is no pattern we can determine at all.

We can't see anybody else with this issue. We have only gone to PushWoosh 6.2.1 as we received an email from PushWoosh saying we needed to upgrade for IOS 10.

We're going to go back to older versions and see what happens.

Any help would be great, we're happy to provide as much logging as needed or send you a development build.

Rob

[shaders]

Could you please try 6.2.2 (just committed with SDK update)?

[rwillett]

Have downloaded and rebuilt.

The first start failed and the 17th startup failed

2016-10-11 07:36:23.702 Jambuster[2811:322149] [PW] [I] __57-[PWPushNotificationsManagerCommon] Registered for push notifications: <<LONG_ID_REMOVED>
2016-10-11 07:36:23.706 Jambuster[2811:322149] Invalid callback id received by sendPluginResult
2016-10-11 07:36:24.646 Jambuster[2811:322149] Finished load of: file:///private/var/mobile/Containers/Bundle/Application/A2D5BC8C-C786-45C6-971A-4CE9917517B7/Jambuster.app/www/index.html#/tab/summary

Is there something specific thats been done to fix this or is this just a new release?

Thanks

Rob

[rwillett]

What is also interesting

1. we can still receive pushed notifications in the background.

   Since the logging is turned on, we can see when we get sent pushed notifications, so somethings is still running

2. We sometimes get the device ready flag as well but not always.

Rob

[rwillett]

We've just done 58 starts and stops of our program and it failed on runs 18, 27, 38 and 58 with the error message

Invalid callback id received by sendPluginResult

The sequence numbers are interesting, almost always the 7th or 8th and spread by an interval of 10 or 20 run.

We simply sat at Xcode and started and stopped the program.

We have also pulled out our commercial geolocation plugin as thats quite large and complex, and still and we still got the above results.

These are our plugins now

com.jcesarmobile.IDFVPlugin 1.0.0 "Identifier For Vendor Plugin" com.rwillett.cordova.plugin.keychainutil 2.0.1 "KeyChain Plugin for Cordova iOS (No iCloud Sync)" cordova-plugin-app-event 1.2.0 "Application Events" cordova-plugin-badge 0.7.2 "Badges" cordova-plugin-battery-status 1.1.1 "Battery" cordova-plugin-console 1.0.3 "Console" cordova-plugin-device 1.1.2 "Device" cordova-plugin-insomnia 4.2.0 "Insomnia (prevent screen sleep)" cordova-plugin-network-information 1.1.0 "Network Information" cordova-plugin-splashscreen 3.2.2 "Splashscreen" cordova-plugin-vibration 2.0.0 "Vibration" cordova-plugin-whitelist 1.2.1 "Whitelist" cordova-plugin-x-toast 2.5.1 "Toast" cordova-sqlite-storage 0.7.14 "Cordova sqlite storage plugin" de.appplant.cordova.plugin.local-notification 0.8.4 "LocalNotification" hu.dpal.phonegap.plugins.UniqueDeviceID 1.2.0 "UniqueDeviceID" ionic-plugin-keyboard 2.2.1 "Keyboard" pushwoosh-cordova-plugin 6.2.2 "Pushwoosh"

We're using Xcode 7.3.1, we're avoiding Xcode 8 for the moment.

We're testing on an iPhone 5s running 8.3 as we know our customers use phones down at this level.

Not sure if there is anything else we can add.

Rob

[rwillett]

Does anybody from Pushwoosh read these boards? Do paying customers have another mechanism for raising bugs?

[wfhm]

Rob, we do read it and we are already investigating this issue, as soon as we figure out something, we will definitely update this thread.

[rwillett]

Thank you. This is stopping us releasing an iOS 10 update for our app.

We are very happy to do anything whatever (thats legal) you need us to do to get to the bottom of this. We can turn around new releases very quickly if that helps. We turned the last update round in 30 mins from memory.

Also happy to continue the conversation privately if thats useful as well. Sometimes a running commentary doesn't help.

You have our full, undivided attention in getting this resolved!

Rob

[skwasjer]

We have this issue as well but it is not limited to iOS 10, it happens on iOS 9 as well. We use ionic, and via $ionicPlatform.ready() our app continues to function and initialize itself.

However, device registration does not always work, as the success callback for registerDevice does not always get called (and the error callback does not get called either in that case). If we keep restarting the app, sometimes it works, sometimes it does not.

What I find odd is that the device is registering itself under the hood, before index.html is loaded, and then registers itself again because we call registerDevice from $ionicPlatform.ready().

2016-10-14 12:24:00.905 [PW] [I] +[UIApplication(Pushwoosh)] Pushwoosh: Initializing application runtime
2016-10-14 12:24:01.061 Apache Cordova native platform version 4.2.1 is starting.
2016-10-14 12:24:01.063 Multi-tasking -> Device: YES, App: YES
2016-10-14 12:24:01.174 Using UIWebView
2016-10-14 12:24:01.178 [CDVTimer][handleopenurl] 0.175953ms
2016-10-14 12:24:01.181 [CDVTimer][intentandnavigationfilter] 3.209949ms
2016-10-14 12:24:01.182 [CDVTimer][gesturehandler] 0.441015ms
2016-10-14 12:24:01.200 [CDVTimer][splashscreen] 18.375993ms
2016-10-14 12:24:01.203 [CDVTimer][keyboard] 1.692951ms
2016-10-14 12:24:01.229 [CDVTimer][file] 25.945008ms
2016-10-14 12:24:01.229 [CDVTimer][TotalPluginStartup] 51.962018ms
2016-10-14 12:24:01.247 [PW] [I] -[PushNotificationManager] Will show push notifications alert: 1
2016-10-14 12:24:01.539 [PW] [I] -[PWLocationTracker] location services authorization status has not been determined yet
2016-10-14 12:24:01.588 Resetting plugins due to page load.
2016-10-14 12:24:01.639 [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://##removed##.api.pushwoosh.com/json/1.3/registerUser
| Payload:  ##removed##
| Status:   "200 no error"
| Response: {"status_code": 200, "status_message": "OK","response":null}
x
2016-10-14 12:24:01.878 [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://##removed##.api.pushwoosh.com/json/1.3/registerDevice
| Payload:  ##removed##
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"iosCategories":[]}}
x
2016-10-14 12:24:01.878 [PW] [I] __57-[PWPushNotificationsManagerCommon] Registered for push notifications: ##removed##
2016-10-14 12:24:01.888 Invalid callback id received by sendPluginResult
2016-10-14 12:24:01.956 Finished load of:  ##removed##/www/index.html
2016-10-14 12:24:02.055 [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://##removed##.api.pushwoosh.com/json/1.3/getInApps
| Payload:  ##removed##
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"inApps":[]}}
x
|    Pushwoosh request:
| Url:      https://##removed##.api.pushwoosh.com/json/1.3/applicationOpen
| Payload:  ##removed##
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-14 12:24:02.923 [PW] [D] __34-[PWDataManagerCommon] sending appOpen completed
2016-10-14 12:24:02.932 [PW] [I] -[PWRequestManager] 
2016-10-14 12:24:08.341 THREAD WARNING: ['PushNotification'] took '10.995850' ms. Plugin should use a background thread.
2016-10-14 12:24:08.353 [PW] [I] -[PWPushNotificationsManagerCommon] Registered for push notifications: ##removed##

You can see the log entry Registered for push notification: ##removed## twice, the last one is triggered by our code (in $ionicPlatform.ready()) but does not always call success callback. The first one, I have no idea where that comes from (perhaps an implicit internal registration, or perhaps the cause of this Invalid callback id received by sendPluginResult message.

I don't know if the success callback not firing is related however.

[rwillett]

We have the same problem, though ours is actually on iOS 8, not iOS 10. We have some customers on iOS 8 and we have to make sure our code works there.

I think but could be completely wrong, that the first registration is simply make a connection and then the next registration, the one where we get the ID back is where we really register the app. However this is purely conjecture.

We had certainly seen events being captured by PushWoosh in the log files even though we had the invalid callback, which appears to match what you have seen.

I'm not pleased you have the issue as well, but I am pleased it's not just us. We were very worried that it was something in our code or plugins or something that we had got wrong. The fact you have the same issue with much the same config, Ionic etc, means its not just us.

Lets see what PushWoosh comes up with.

Rob

[shaders]

I've found a reason for this error. I'll push the update later today. But that's really weird that your app stops working.

This happens when registerDevice calls the nil phonegap callback. But the code in Cordova is super safe there:

    // This occurs when the callback id is malformed.
    if (![self isValidCallbackId:callbackId]) {
        NSLog(@"Invalid callback id received by sendPluginResult");
        return;
    }

It shouldn't crash your app or prevent it from run any further.

[rwillett]

I'd seen this code already.

I recall this code is in the Cordova basecode (but could be wrong).

I think that the problem is occurring elsewhere though and this just shows the error. However thats just our guess.

It definitely causes an issue, sometimes it stops the deviceReady event and sometimes it doesn't. Other people have reported the same, though its not clear what the common denominator is.

Let us know when the code is updated and we'll immediately update and feedback. We spent yesterday refactoring our notifications code so that it works with PushWoosh 4.2.2 and (hopefully) with 6.2.x so we can get a release out real-soon-now.

Our next problem is IOS and Xcode 8.0 and Cordova. We really don't want to upgrade :)

Rob

[DimanAM]

@rwillett Since this is causing your app to crash there should be a crash log. Could you please share it?

[rwillett]

I phrased my question poorly in the very first post. The app stops but I didn't recall an actual crash, e.g. Xcode showing crash information.

It often hung soon after the

Invalid callback id received by sendPluginResult

and so we never received a device ready event. Sometimes we did though. I used the phrase crash and should have used the hung instead.

I cannot recall an actual crash. We're finishing off refactoring notification code this morning (I hope) and will retry with the 6.2.2 PushWoosh code and see if we can generate a crash. if we can, we have no issues with sharing the crash logs.

[DimanAM]

Unfortunately I could not reproduce the problem. I've added check for "registerDevice" callback id. If the issue still persists, please try collecting more detailed logs by setting CDV_ENABLE_EXEC_LOGGING to 1 in platforms/ios/CordovaLib/Classes/CDVAvailability.h.

[rwillett]

@DimanAM , @shaders,

We'll play about with stuff later today. I'm unclear as to who is who and what their role is with PushWoosh (if at all), before we send any crash logs. Thats assuming we can create some :)

Could you let me know who you are please?

Rob

[shaders]

If the logs could contain sensitive information, please send it to Pushwoosh support, just note this thread on GitHub, they will send the logs to us.

Thanks1

[rwillett]

Haven't managed to create any crash logs so far. We've just finished a build for alpha testing for IOS 10 using PushWoosh 4.2.2.

We'll have try tomorrow with PushWoosh 6.2.2.

Rob

[rwillett]

We've just downloaded and built our app with PushWoosh 6.2.5 and we are still having hanging errors, though the original error is no longer being shown.

We started the app 42 times and had the following hangs on run 1, 11, 12, 27 and 42.

Here's the output from Xcode when it hangs

2016-10-19 23:42:45.981 Jambuster[1300:319289] [PW] [E] Error! Invalid log level. Setting default (DEBUG)
2016-10-19 23:42:45.983 Jambuster[1300:319289] [PW] [I] +[UIApplication(Pushwoosh)] Pushwoosh: Initializing application runtime
2016-10-19 23:42:46.004 Jambuster[1300:319289] DiskCookieStorage changing policy from 2 to 0, cookie file: file:///private/var/mobile/Containers/Data/Application/F988A0AF-579C-40D5-9561-8192FC4F68E1/Library/Cookies/Cookies.binarycookies
2016-10-19 23:42:46.151 Jambuster[1300:319289] Apache Cordova native platform version 4.1.1 is starting.
2016-10-19 23:42:46.152 Jambuster[1300:319289] Multi-tasking -> Device: YES, App: YES
2016-10-19 23:42:46.230 Jambuster[1300:319289] Using UIWebView
2016-10-19 23:42:46.232 Jambuster[1300:319289] [CDVTimer][handleopenurl] 0.122011ms
2016-10-19 23:42:46.235 Jambuster[1300:319289] [CDVTimer][intentandnavigationfilter] 2.636015ms
2016-10-19 23:42:46.236 Jambuster[1300:319289] [CDVTimer][gesturehandler] 0.094950ms
2016-10-19 23:42:46.268 Jambuster[1300:319289] [CDVTimer][splashscreen] 31.922996ms
2016-10-19 23:42:46.269 Jambuster[1300:319289] [CDVTimer][localnotification] 0.537992ms
2016-10-19 23:42:46.269 Jambuster[1300:319289] [CDVTimer][localnotification] 0.014007ms
2016-10-19 23:42:46.269 Jambuster[1300:319289] [CDVTimer][uniquedeviceid] 0.091016ms
2016-10-19 23:42:46.270 Jambuster[1300:319289] [CDVTimer][keyboard] 0.666976ms
2016-10-19 23:42:46.270 Jambuster[1300:319289] [CDVTimer][backgroundfetch] 0.140011ms
2016-10-19 23:42:46.271 Jambuster[1300:319289] [CDVTimer][TotalPluginStartup] 38.452983ms
2016-10-19 23:42:46.277 Jambuster[1300:319289] [PW] [I] -[PushNotificationManager] Will show push notifications alert: 1
2016-10-19 23:42:46.471 Jambuster[1300:319289] Resetting plugins due to page load.
2016-10-19 23:42:46.633 Jambuster[1300:319289] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/registerUser
| Payload:  {"request":{"device_type":1,"application":"<<REMOVED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code": 200, "status_message": "OK","response":null}
x
2016-10-19 23:42:46.773 Jambuster[1300:319289] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/getInApps
| Payload:  {"request":{"device_type":1,"language":"en","application":"<<REMOVED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"inApps":[]}}
x
2016-10-19 23:42:46.779 Jambuster[1300:319289] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/registerDevice
| Payload:  {"request":{"gateway":"sandbox","jailbroken":0,"app_version":"1.6.7","application":"<<REMOVED>>","sounds":[],"device_type":1,"userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","language":"en","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A","package":"<<REMOVED>>","timezone":"3600","push_token":"502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2","os_version":"8.3","device_model":"iPhone6,2","v":"4.1.6"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"iosCategories":[]}}
x
2016-10-19 23:42:46.779 Jambuster[1300:319289] [PW] [I] __57-[PWPushNotificationsManagerCommon] Registered for push notifications: 502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2
2016-10-19 23:42:47.898 Jambuster[1300:319289] Finished load of: file:///private/var/mobile/Containers/Bundle/Application/65126B0C-86B3-4B7E-96E2-C5D9D9F8F1DB/Jambuster.app/www/index.html#/tab/summary
2016-10-19 23:42:48.143 Jambuster[1300:319289] CL BACKLOG:[ 0] 19/10/2016 @ 23:42:48 <<< $ionicPlatform.ready >>>
2016-10-19 23:42:48.143 Jambuster[1300:319289] RegisterAndGetUUID function called
2016-10-19 23:42:48.169 Jambuster[1300:319289] RegisterAndGetPushWooshNotificationIDS called. UUID=D26FBAF1-2EF2-4614-875F-4497EC4212D5/JFL1-0/ios_app
2016-10-19 23:42:48.169 Jambuster[1300:319289] Kicking off pushNotification = cordova.require('pushwoosh-cordova-plugin.PushNotification');
2016-10-19 23:42:48.171 Jambuster[1300:319289] Now registering device
2016-10-19 23:42:48.180 Jambuster[1300:319289] [PW] [I] -[PWPushNotificationsManagerCommon] Registered for push notifications: 502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2
2016-10-19 23:42:48.410 Jambuster[1300:319289] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/applicationOpen
| Payload:  {"request":{"userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","app_version":"1.6.7","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A","language":"en","os_version":"8.3","package":"london.jambuster.client10000","v":"4.1.6","application":"<<REMOVED>>","device_type":1,"jailbroken":0,"device_model":"iPhone6,2"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-19 23:42:48.411 Jambuster[1300:319289] [PW] [D] __34-[PWDataManagerCommon] sending appOpen completed

Sometimes the device ready event would be fired and we can see notifications turning up. However the function pushNotification.registerDevice() is NOT being called which we need as it supplies the deviceToken/pushToken. This is very similar to the last problem.

Here's the output if we leave the program running. We can see that we are catching notifications but the pushNotification.registerDevice() has never come back. We highlight the point in the output where we would expect to see it.

2016-10-19 23:58:00.540 Jambuster[1443:328802] [PW] [I] +[UIApplication(Pushwoosh) load] Pushwoosh: Initializing application runtime
2016-10-19 23:58:00.561 Jambuster[1443:328802] DiskCookieStorage changing policy from 2 to 0, cookie file: file:///private/var/mobile/Containers/Data/Application/07995291-049E-4605-B730-4463131D9D08/Library/Cookies/Cookies.binarycookies
2016-10-19 23:58:00.574 Jambuster[1443:328802] CDVBackgroundFetch AppDelegate received fetch event
2016-10-19 23:58:00.575 Jambuster[1443:328802] - TSBackgroundFetch performFetchWithCompletionHandler
2016-10-19 23:58:00.701 Jambuster[1443:328802] Apache Cordova native platform version 4.1.1 is starting.
2016-10-19 23:58:00.701 Jambuster[1443:328802] Multi-tasking -> Device: YES, App: YES
2016-10-19 23:58:00.787 Jambuster[1443:328802] Using UIWebView
2016-10-19 23:58:00.789 Jambuster[1443:328802] [CDVTimer][handleopenurl] 0.105977ms
2016-10-19 23:58:00.793 Jambuster[1443:328802] [CDVTimer][intentandnavigationfilter] 2.883971ms
2016-10-19 23:58:00.793 Jambuster[1443:328802] [CDVTimer][gesturehandler] 0.119030ms
2016-10-19 23:58:00.826 Jambuster[1443:328802] [CDVTimer][splashscreen] 32.214999ms
2016-10-19 23:58:00.827 Jambuster[1443:328802] [CDVTimer][localnotification] 0.550032ms
2016-10-19 23:58:00.827 Jambuster[1443:328802] [CDVTimer][localnotification] 0.014007ms
2016-10-19 23:58:00.827 Jambuster[1443:328802] [CDVTimer][uniquedeviceid] 0.092030ms
2016-10-19 23:58:00.828 Jambuster[1443:328802] [CDVTimer][keyboard] 0.831008ms
2016-10-19 23:58:00.828 Jambuster[1443:328802] [CDVTimer][backgroundfetch] 0.089049ms
2016-10-19 23:58:00.829 Jambuster[1443:328802] [CDVTimer][TotalPluginStartup] 39.425969ms
2016-10-19 23:58:00.835 Jambuster[1443:328802] [PW] [I] -[PushNotificationManager initWithApplicationCode:appName:] Will show push notifications alert: 1
2016-10-19 23:58:01.072 Jambuster[1443:328802] Resetting plugins due to page load.
2016-10-19 23:58:01.275 Jambuster[1443:328802] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/registerUser
| Payload:  {"request":{"device_type":1,"application":"REDACTED","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code": 200, "status_message": "OK","response":null}
x
2016-10-19 23:58:01.418 Jambuster[1443:328802] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/registerDevice
| Payload:  {"request":{"gateway":"sandbox","jailbroken":0,"app_version":"1.6.7","application":"REDACTED","sounds":[],"device_type":1,"userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","language":"en","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A","package":"REDACTED","timezone":"3600","push_token":"502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2","os_version":"8.3","device_model":"iPhone6,2","v":"4.1.6"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"iosCategories":[]}}
x
2016-10-19 23:58:01.418 Jambuster[1443:328802] [PW] [I] __57-[PWPushNotificationsManagerCommon sendDevTokenToServer:]_block_invoke Registered for push notifications: 502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2

2016-10-19 23:58:01.420 Jambuster[1443:328802] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/getInApps
| Payload:  {"request":{"device_type":1,"language":"en","application":"REDACTED","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"inApps":[]}}
x
2016-10-19 23:58:02.508 Jambuster[1443:328802] Finished load of: file:///private/var/mobile/Containers/Bundle/Application/32CA05F0-9FC5-41A6-918F-4DFB4D244B01/Jambuster.app/www/index.html#/tab/summary
2016-10-19 23:58:02.708 Jambuster[1443:328802] CL BACKLOG:[ 0] 19/10/2016 @ 23:58:02 <<< $ionicPlatform.ready >>>
2016-10-19 23:58:02.709 Jambuster[1443:328802] RegisterAndGetUUID function called
2016-10-19 23:58:02.754 Jambuster[1443:328802] RegisterAndGetPushWooshNotificationIDS called. UUID=D26FBAF1-2EF2-4614-875F-4497EC4212D5/JFL1-0/ios_app
2016-10-19 23:58:02.754 Jambuster[1443:328802] Kicking off pushNotification = cordova.require('pushwoosh-cordova-plugin.PushNotification');
2016-10-19 23:58:02.756 Jambuster[1443:328802] Now registering device

----------------------------------------------> WE EXPECT TO SEE CONFIRMATION THAT  pushNotification.registerDevice() HAS WORKED JUST HERE

2016-10-19 23:58:02.764 Jambuster[1443:328802] [PW] [I] -[PWPushNotificationsManagerCommon sendDevTokenToServer:] Registered for push notifications: 502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2
2016-10-19 23:58:02.825 Jambuster[1443:328802] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/applicationOpen
| Payload:  {"request":{"userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","app_version":"1.6.7","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A","language":"en","os_version":"8.3","package":"REDACTED","v":"4.1.6","application":"REDACTED","device_type":1,"jailbroken":0,"device_model":"iPhone6,2"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-19 23:58:02.826 Jambuster[1443:328802] [PW] [D] __34-[PWDataManagerCommon sendAppOpen]_block_invoke sending appOpen completed
2016-10-19 23:58:23.276 Jambuster[1443:328802] [PW] [D] -[PushNotification onPushAccepted:withNotification:onStart:] Notification opened: {
    foreground = 1;
    ios =     {
        aps =         {
            badge = 0;
            "content-available" = 1;
        };
    };
    onStart = 0;
}
2016-10-19 23:58:23.299 Jambuster[1443:328802] ConvertIOSPushWooshEventForQueue: event = {"notification":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:23.299 Jambuster[1443:328802] ConvertIOSPushWooshEventForQueue: config = {"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:23.300 Jambuster[1443:328802] *************************
2016-10-19 23:58:23.300 Jambuster[1443:328802] ***** HandlePushWooshIOSNotification: event = {"notification":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:23.300 Jambuster[1443:328802] ***** HandlePushWooshIOSNotification: iOSConvertedPushWooshNotification = {"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:23.300 Jambuster[1443:328802] *************************
2016-10-19 23:58:23.300 Jambuster[1443:328802] *****
2016-10-19 23:58:23.300 Jambuster[1443:328802] HandleNotificationEvent: event 2016-10-19T23:58:23Z -> {"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:23.301 Jambuster[1443:328802] *****
2016-10-19 23:58:23.302 Jambuster[1443:328802] ===============
2016-10-19 23:58:23.302 Jambuster[1443:328802] HandleNotificationEvent: Checking if we need to clear old notifications out
2016-10-19 23:58:23.302 Jambuster[1443:328802] ===============
2016-10-19 23:58:23.302 Jambuster[1443:328802] AddToExecutionQueue: [{"functionName":"HandleNotificationAtStartup","functionArgs":{"notification":{"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}},"name":"HandleNotificationEvent"}}]
2016-10-19 23:58:23.303 Jambuster[1443:328802] AddToExecutionQueue: executionQueueTimeout = 65
2016-10-19 23:58:23.303 Jambuster[1443:328802] ConvertIOSPushWooshEventForQueue: event = {"notification":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:23.303 Jambuster[1443:328802] ConvertIOSPushWooshEventForQueue: config = {"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:23.304 Jambuster[1443:328802] *************************
2016-10-19 23:58:23.304 Jambuster[1443:328802] ***** HandlePushWooshIOSNotification: event = {"notification":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:23.305 Jambuster[1443:328802] ***** HandlePushWooshIOSNotification: iOSConvertedPushWooshNotification = {"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:23.305 Jambuster[1443:328802] *************************
2016-10-19 23:58:23.305 Jambuster[1443:328802] *****
2016-10-19 23:58:23.305 Jambuster[1443:328802] HandleNotificationEvent: event 2016-10-19T23:58:23Z -> {"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:23.305 Jambuster[1443:328802] *****
2016-10-19 23:58:23.306 Jambuster[1443:328802] ===============
2016-10-19 23:58:23.309 Jambuster[1443:328802] HandleNotificationEvent: Checking if we need to clear old notifications out
2016-10-19 23:58:23.309 Jambuster[1443:328802] ===============
2016-10-19 23:58:23.309 Jambuster[1443:328802] AddToExecutionQueue: [{"functionName":"HandleNotificationAtStartup","functionArgs":{"notification":{"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}},"name":"HandleNotificationEvent"}},{"functionName":"HandleNotificationAtStartup","functionArgs":{"notification":{"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}},"name":"HandleNotificationEvent"}}]
2016-10-19 23:58:23.310 Jambuster[1443:328802] AddToExecutionQueue: executionQueueTimeout = 66
2016-10-19 23:58:23.313 Jambuster[1443:328802] pushNotification.cancelAllLocalNotifications succeeded
2016-10-19 23:58:23.313 Jambuster[1443:328802] pushNotification.cancelAllLocalNotifications succeeded
2016-10-19 23:58:23.337 Jambuster[1443:328802] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":0,"application":"REDACTED","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-19 23:58:23.337 Jambuster[1443:328802] [PW] [D] __34-[PWDataManagerCommon sendBadges:]_block_invoke setBadges completed
2016-10-19 23:58:24.312 Jambuster[1443:328802] -
2016-10-19 23:58:24.313 Jambuster[1443:328802] ExecuteNotificationAtStartup: info={"notification":{"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}},"name":"HandleNotificationEvent"}
2016-10-19 23:58:24.313 Jambuster[1443:328802] ExecuteNotificationAtStartup: notification={"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:24.314 Jambuster[1443:328802] ExecuteNotificationAtStartup: name="HandleNotificationEvent"
2016-10-19 23:58:24.323 Jambuster[1443:328802] Calling GetNotificationsFromServer with {"additionalData":{"Foreground":true},"originalPushWooshEvent":{"onStart":false,"foreground":true,"ios":{"aps":{"badge":0,"content-available":1}}}}
2016-10-19 23:58:24.416 Jambuster[1443:328802] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":1,"application":"REDACTED","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-19 23:58:24.417 Jambuster[1443:328802] [PW] [D] __34-[PWDataManagerCommon sendBadges:]_block_invoke setBadges completed
2016-10-19 23:58:24.437 Jambuster[1443:328802] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":0,"application":"REDACTED","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-19 23:58:24.437 Jambuster[1443:328802] [PW] [D] __34-[PWDataManagerCommon sendBadges:]_block_invoke setBadges completed
2016-10-19 23:58:24.529 Jambuster[1443:328802] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":1,"application":"REDACTED","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-19 23:58:24.529 Jambuster[1443:328802] [PW] [D] __34-[PWDataManagerCommon sendBadges:]_block_invoke setBadges completed
2016-10-19 23:58:24.529 Jambuster[1443:328802] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":0,"application":"REDACTED","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-19 23:58:24.530 Jambuster[1443:328802] [PW] [D] __34-[PWDataManagerCommon sendBadges:]_block_invoke setBadges completed
2016-10-19 23:58:24.544 Jambuster[1443:328802] [PW] [I] -[PWRequestManager processResponse:responseData:request:url:requestData:error:] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":0,"application":"REDACTED","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-19 23:58:24.544 Jambuster[1443:328802] [PW] [D] __34-[PWDataManagerCommon sendBadges:]_block_invoke setBadges completed
2016-10-20 00:02:25.764 Jambuster[1443:328802] [PW] [D] -[PushNotification onPushAccepted:withNotification:onStart:] Notification opened: {
    foreground = 1;
    ios =     {
        aps =         {
            badge = 0;
            "content-available" = 1;
        };
    };
    onStart = 0;
}

We've been through the docs again and we haven't changed our code. We know the code and pushNotification.registerDevice() works under PushWoosh 4.2.2 as we've spent the day testing it.

We're happy to send complete code samples and unredacted log files if that helps.

Rob

[rwillett]

Just did another run this morning, we ran it 28 times before we had a hang.

We've been discussing the issue internally and trying to think what the issue could be.

The only suggestions we can come up with are:

1. Some sort of race condition. e.g. some code isn't being loaded in exactly the same sequence.
2. Something is kicking off before it should so.
3. We have wrapped the whole of our function RegisterAndGetPushWooshNotificationIDS() which registers the user with PushWoosh in an angular promise. This was an architectural decision made when we started development some 18 months ago. We can't see why this is an issue, but we wondered if it might be. We can state that the PushWoosh code 4.2.2 works fine with the Angular promise.
4. Some sort or variable name space problem, unlikely but you never know.
5. We have registered two event listeners for handling both push-notification and push-receive.

document.addEventListener('push-notification', HandlePushWooshIOSNotification);
document.addEventListener('push-receive', HandlePushWooshIOSNotification);

We do this as we wanted to handle both PushWoosh 4.2.2 and PushWoosh 6.2.5 plugins.

We're going to cut down our registration function to the minimum and see if we can remove the Angular promise. Removing the promise is not easy as we use that sort of pattern all over the place and we have come to rely on it.

Any other suggestions welcomed.

Rob

[zarko-tg]

We are also experiencing a problem with registerDevice never returning with any of its two callback functions. Using pushwoosh-cordova-plugin 6.2.5 and device iOS 10.1 (14B72). Haven't checked myself on previous iOS versions but it seems the issue is still there. Android seems unaffected.

It's used in an Ionic app, and as far as I an tell this problem has been there for a while (not less than a year) for iOS/and the plugin. We use a concept of app user, where we unregister from push on "logout" and register on "login". In our case the "logout"/unregistration is followed by a window.reload.

For a fresh install and login everything is fine wrt. push but once I log out the user and so unregister we hit the problem with the callbacks. Some time ago this happened now and then (randomish) but now is see the problem always.

Great if you can prioritize this case guys.

[rwillett]

We're testing on IOS 8.4 (I know) as customers still have it.

We have not really tested on IOS 10 as we didn't want to upgrade to Xcode 8.0 until we'd resolved the Cordova issues with building. We have done a TestFlight build with PushWoosh 4.2.2 and IOS 10 and confirmed that PushWoosh 4.2.2 doesn't work with IOS 10 which is a bummer. We have no need to upgrade to PushWoosh 6.2.5 as we have all the functionality in 4.2.2.

No issues so far on Android.

We only used PushWoosh 4.2.2 until iOS 10.0 and we needed to upgrade as IOS 10.0 and PushWoosh 4.2.2 don't work together. We've been using 4.2.2 for a long time with no problems.

We don't have the concept of login/logout apart from starting the app up, but is sounds as if we have the same issues.

We don't have the issue all the time though. It is random, hence we think its a race condition or similar.

Rob

[shaders]

@zarko-tg @rwillett Are you sure you are not calling push unregistration? See my last comment on this thread. Calling push unregistration completely breaks everything. Looks like we just hit a bug in iOS 10...

https://github.com/Pushwoosh/pushwoosh-unity/issues/18#issuecomment-255362579

[rwillett]

100% positive not calling push unregistration. Didn't even know about it the function :)

Sorry

Rob

[shaders]

@rwillett could you try two things for me please.

1. Please open PushNotification.m file Look for this string (should be in 2 places in the file) //Cordova BUG: https://issues.apache.org/jira/browse/CB-8063

Uncomment 3 lines below.

Try if this fixes your issue.

If it doesnt:

2. Please set CDV_ENABLE_EXEC_LOGGING to 1 in platforms/ios/CordovaLib/Classes/CDVAvailability.h.

Just search for CDV_ENABLE_EXEC_LOGGING and you'll see it. And get the logs.

Thanks!

[rwillett]

1. Changed over the three lines after the BUG comment in the files

./platforms/ios/Jambuster/Plugins/pushwoosh-cordova-plugin/ios/PushNotification.m and ./plugins/pushwoosh-cordova-plugin/src/ios/PushNotification.m

as I wasn't sure which is the master and which is the slave. So did them both to make sure :) (I think that ./platforms/ios/Jambuster/Plugins/pushwoosh-cordova-plugin/ios/PushNotification.m is the master though)

Compiled as normal.

Failed on 7th restart.

Heres' the full log from that run.

2016-10-22 08:19:57.569 Jambuster[5628:614955] [PW] [E] Error! Invalid log level. Setting default (DEBUG)
2016-10-22 08:19:57.571 Jambuster[5628:614955] [PW] [I] +[UIApplication(Pushwoosh)] Pushwoosh: Initializing application runtime
2016-10-22 08:19:57.606 Jambuster[5628:614955] CDVBackgroundFetch AppDelegate received fetch event
2016-10-22 08:19:57.606 Jambuster[5628:614955] - TSBackgroundFetch performFetchWithCompletionHandler
2016-10-22 08:19:57.760 Jambuster[5628:614955] Apache Cordova native platform version 4.1.1 is starting.
2016-10-22 08:19:57.760 Jambuster[5628:614955] Multi-tasking -> Device: YES, App: YES
2016-10-22 08:19:57.857 Jambuster[5628:614955] Using UIWebView
2016-10-22 08:19:57.859 Jambuster[5628:614955] [CDVTimer][handleopenurl] 0.095010ms
2016-10-22 08:19:57.862 Jambuster[5628:614955] [CDVTimer][intentandnavigationfilter] 2.726972ms
2016-10-22 08:19:57.863 Jambuster[5628:614955] [CDVTimer][gesturehandler] 0.104010ms
2016-10-22 08:19:57.907 Jambuster[5628:614955] [CDVTimer][splashscreen] 44.131041ms
2016-10-22 08:19:57.908 Jambuster[5628:614955] [CDVTimer][localnotification] 0.521004ms
2016-10-22 08:19:57.908 Jambuster[5628:614955] [CDVTimer][localnotification] 0.014961ms
2016-10-22 08:19:57.908 Jambuster[5628:614955] [CDVTimer][uniquedeviceid] 0.092983ms
2016-10-22 08:19:57.909 Jambuster[5628:614955] [CDVTimer][keyboard] 0.646949ms
2016-10-22 08:19:57.910 Jambuster[5628:614955] [CDVTimer][backgroundfetch] 0.127017ms
2016-10-22 08:19:57.910 Jambuster[5628:614955] [CDVTimer][TotalPluginStartup] 50.807953ms
2016-10-22 08:19:57.917 Jambuster[5628:614955] [PW] [I] -[PushNotificationManager] Will show push notifications alert: 1
2016-10-22 08:19:58.169 Jambuster[5628:614955] Resetting plugins due to page load.
2016-10-22 08:19:58.382 Jambuster[5628:614955] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/getInApps
| Payload:  {"request":{"device_type":1,"language":"en","application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"inApps":[]}}
x
2016-10-22 08:19:58.713 Jambuster[5628:614955] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/registerUser
| Payload:  {"request":{"device_type":1,"application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code": 200, "status_message": "OK","response":null}
x
2016-10-22 08:19:58.714 Jambuster[5628:614955] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/registerDevice
| Payload:  {"request":{"gateway":"sandbox","jailbroken":0,"app_version":"1.6.7","application":"<<REDACTED>>","sounds":[],"device_type":1,"userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","language":"en","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A","package":"<<REDACTED>>","timezone":"3600","push_token":"502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2","os_version":"8.3","device_model":"iPhone6,2","v":"4.1.6"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"iosCategories":[]}}
x
2016-10-22 08:19:58.716 Jambuster[5628:614955] [PW] [I] __57-[PWPushNotificationsManagerCommon] Registered for push notifications: 502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2
2016-10-22 08:19:59.543 Jambuster[5628:614955] Finished load of: file:///private/var/mobile/Containers/Bundle/Application/4E9F8C8D-D924-4963-B536-CB4C26ED0A96/Jambuster.app/www/index.html#/tab/summary
2016-10-22 08:19:59.800 Jambuster[5628:614955] CL BACKLOG:[ 0] 22/10/2016 @ 08:19:59 <<< $ionicPlatform.ready >>>
2016-10-22 08:19:59.801 Jambuster[5628:614955] RegisterAndGetUUID function called
2016-10-22 08:19:59.825 Jambuster[5628:614955] RegisterAndGetPushWooshNotificationIDS called. UUID=D26FBAF1-2EF2-4614-875F-4497EC4212D5/JFL1-0/ios_app
2016-10-22 08:19:59.825 Jambuster[5628:614955] RegisterAndGetPushWooshNotificationIDS: Kicking off pushNotification = cordova.require('pushwoosh-cordova-plugin.PushNotification');
2016-10-22 08:19:59.827 Jambuster[5628:614955] Now registering device
2016-10-22 08:19:59.835 Jambuster[5628:614955] [PW] [I] -[PWPushNotificationsManagerCommon] Registered for push notifications: 502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2
2016-10-22 08:19:59.959 Jambuster[5628:614955] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/applicationOpen
| Payload:  {"request":{"userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","app_version":"1.6.7","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A","language":"en","os_version":"8.3","package":"<<REDACTED>>","v":"4.1.6","application":"A2EE0-23D28","device_type":1,"jailbroken":0,"device_model":"iPhone6,2"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-22 08:19:59.959 Jambuster[5628:614955] [PW] [D] __34-[PWDataManagerCommon] sending appOpen completed

1. Changed set CDV_ENABLE_EXEC_LOGGING to 1 in platforms/ios/CordovaLib/Classes/CDVAvailability.h

and failed on 1st and 4th run. Here's the full logs from that failed 4th run.

I have also attached the logs from a successful run at the end, this is getting a long reply :) We're going to look through these as well.

2016-10-22 08:25:05.782 Jambuster[5650:616477] [PW] [E] Error! Invalid log level. Setting default (DEBUG)
2016-10-22 08:25:05.784 Jambuster[5650:616477] [PW] [I] +[UIApplication(Pushwoosh)] Pushwoosh: Initializing application runtime
2016-10-22 08:25:05.963 Jambuster[5650:616477] Apache Cordova native platform version 4.1.1 is starting.
2016-10-22 08:25:05.964 Jambuster[5650:616477] Multi-tasking -> Device: YES, App: YES
2016-10-22 08:25:06.058 Jambuster[5650:616477] Using UIWebView
2016-10-22 08:25:06.060 Jambuster[5650:616477] [CDVTimer][handleopenurl] 0.092983ms
2016-10-22 08:25:06.063 Jambuster[5650:616477] [CDVTimer][intentandnavigationfilter] 2.620041ms
2016-10-22 08:25:06.063 Jambuster[5650:616477] [CDVTimer][gesturehandler] 0.087023ms
2016-10-22 08:25:06.105 Jambuster[5650:616477] [CDVTimer][splashscreen] 40.986001ms
2016-10-22 08:25:06.105 Jambuster[5650:616477] [CDVTimer][localnotification] 0.491977ms
2016-10-22 08:25:06.106 Jambuster[5650:616477] [CDVTimer][localnotification] 0.015020ms
2016-10-22 08:25:06.106 Jambuster[5650:616477] [CDVTimer][uniquedeviceid] 0.090003ms
2016-10-22 08:25:06.107 Jambuster[5650:616477] [CDVTimer][keyboard] 0.640035ms
2016-10-22 08:25:06.107 Jambuster[5650:616477] [CDVTimer][backgroundfetch] 0.151992ms
2016-10-22 08:25:06.107 Jambuster[5650:616477] [CDVTimer][TotalPluginStartup] 47.405958ms
2016-10-22 08:25:06.114 Jambuster[5650:616477] [PW] [I] -[PushNotificationManager] Will show push notifications alert: 1
2016-10-22 08:25:06.283 Jambuster[5650:616477] Exec: evalling: try{cordova.require('cordova/exec').nativeEvalAndFetch(function(){cordova.fireDocumentEvent('active');})}catch(e){console.log('exeption nativeEvalAndFetch : '+e
2016-10-22 08:25:06.341 Jambuster[5650:616477] Resetting plugins due to page load.
2016-10-22 08:25:06.576 Jambuster[5650:616477] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/registerUser
| Payload:  {"request":{"device_type":1,"application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code": 200, "status_message": "OK","response":null}
x
2016-10-22 08:25:06.721 Jambuster[5650:616477] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/getInApps
| Payload:  {"request":{"device_type":1,"language":"en","application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"inApps":[]}}
x
2016-10-22 08:25:06.733 Jambuster[5650:616477] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/registerDevice
| Payload:  {"request":{"gateway":"sandbox","jailbroken":0,"app_version":"1.6.7","application":"<<REDACTED>>","sounds":[],"device_type":1,"userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","language":"en","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A","package":"<<REDACTED>>","timezone":"3600","push_token":"502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2","os_version":"8.3","device_model":"iPhone6,2","v":"4.1.6"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"iosCategories":[]}}
x
2016-10-22 08:25:06.734 Jambuster[5650:616477] [PW] [I] __57-[PWPushNotificationsManagerCommon] Registered for push notifications: 502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2
2016-10-22 08:25:07.765 Jambuster[5650:616477] Finished load of: file:///private/var/mobile/Containers/Bundle/Application/DB83EF23-139E-4B6B-A263-83F1BC72E747/Jambuster.app/www/index.html#/tab/summary
2016-10-22 08:25:07.942 Jambuster[5650:616477] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:25:07.943 Jambuster[5650:616477] Exec(Device1060920407): Calling Device.getDeviceInfo
2016-10-22 08:25:07.944 Jambuster[5650:616477] Exec(Device1060920407): Sending result. Status=1
2016-10-22 08:25:07.944 Jambuster[5650:616477] Exec: evalling: cordova.require('cordova/exec').nativeCallback('Device1060920407',1,{"manufacturer":"Apple","platform":"iOS","model":"iPhone6,2","uuid":"257B5BB6-D9C9-421E-A125
2016-10-22 08:25:07.950 Jambuster[5650:616477] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:25:07.950 Jambuster[5650:616477] Exec(NetworkStatus1060920408): Calling NetworkStatus.getConnectionInfo
2016-10-22 08:25:07.953 Jambuster[5650:616477] Exec(NetworkStatus1060920408): Sending result. Status=1
2016-10-22 08:25:07.953 Jambuster[5650:616477] Exec: evalling: cordova.require('cordova/exec').nativeCallback('NetworkStatus1060920408',1,"wifi",1, 1)
2016-10-22 08:25:08.021 Jambuster[5650:616477] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:25:08.022 Jambuster[5650:616477] Exec(INVALID): Calling LocalNotification.deviceready
2016-10-22 08:25:08.022 Jambuster[5650:616477] Exec(INVALID): Calling Keyboard.disableScroll
2016-10-22 08:25:08.023 Jambuster[5650:616477] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:25:08.023 Jambuster[5650:616477] CL BACKLOG:[ 0] 22/10/2016 @ 08:25:07 <<< $ionicPlatform.ready >>>
2016-10-22 08:25:08.023 Jambuster[5650:616477] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:25:08.024 Jambuster[5650:616477] RegisterAndGetUUID function called
2016-10-22 08:25:08.024 Jambuster[5650:616477] Exec(Keychain1060920409): Calling Keychain.getForKey
2016-10-22 08:25:08.033 Jambuster[5650:616495] Exec(Keychain1060920409): Sending result. Status=1
2016-10-22 08:25:08.033 Jambuster[5650:616477] Exec: evalling: cordova.require('cordova/exec').nativeCallback('Keychain1060920409',1,"D26FBAF1-2EF2-4614-875F-4497EC4212D5\/JFL1-0\/ios_app",0, 1)
2016-10-22 08:25:08.049 Jambuster[5650:616477] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:25:08.050 Jambuster[5650:616477] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:25:08.050 Jambuster[5650:616477] RegisterAndGetPushWooshNotificationIDS called. UUID=D26FBAF1-2EF2-4614-875F-4497EC4212D5/JFL1-0/ios_app
2016-10-22 08:25:08.050 Jambuster[5650:616477] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:25:08.050 Jambuster[5650:616477] RegisterAndGetPushWooshNotificationIDS: Kicking off pushNotification = cordova.require('pushwoosh-cordova-plugin.PushNotification');
2016-10-22 08:25:08.050 Jambuster[5650:616477] Exec(INVALID): Calling PushNotification.onDeviceReady
2016-10-22 08:25:08.052 Jambuster[5650:616477] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:25:08.052 Jambuster[5650:616477] Now registering device
2016-10-22 08:25:08.052 Jambuster[5650:616477] Exec(PushNotification1060920410): Calling PushNotification.registerDevice
2016-10-22 08:25:08.053 Jambuster[5650:616477] Exec(PushNotification1060920410): Sending result. Status=0
2016-10-22 08:25:08.054 Jambuster[5650:616477] Exec: evalling: cordova.require('cordova/exec').nativeCallback('PushNotification1060920410',0,null,1, 1)
2016-10-22 08:25:08.062 Jambuster[5650:616477] [PW] [I] -[PWPushNotificationsManagerCommon] Registered for push notifications: 502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2
2016-10-22 08:25:08.155 Jambuster[5650:616477] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/applicationOpen
| Payload:  {"request":{"userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","app_version":"1.6.7","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A","language":"en","os_version":"8.3","package":"<<REDACTED>>","v":"4.1.6","application":"<<REDACTED>>","device_type":1,"jailbroken":0,"device_model":"iPhone6,2"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-22 08:25:08.156 Jambuster[5650:616477] [PW] [D] __34-[PWDataManagerCommon] sending appOpen completed

This the log files from the successful start. Clearly it has more stuff in as our app has started up. We use a paid for geolocation plugin which is the geolocation stuff in the middle.

2016-10-22 08:31:22.648 Jambuster[5669:617846] [PW] [E] Error! Invalid log level. Setting default (DEBUG)
2016-10-22 08:31:22.650 Jambuster[5669:617846] [PW] [I] +[UIApplication(Pushwoosh)] Pushwoosh: Initializing application runtime
2016-10-22 08:31:22.827 Jambuster[5669:617846] Apache Cordova native platform version 4.1.1 is starting.
2016-10-22 08:31:22.827 Jambuster[5669:617846] Multi-tasking -> Device: YES, App: YES
2016-10-22 08:31:22.921 Jambuster[5669:617846] Using UIWebView
2016-10-22 08:31:22.924 Jambuster[5669:617846] [CDVTimer][handleopenurl] 0.096023ms
2016-10-22 08:31:22.927 Jambuster[5669:617846] [CDVTimer][intentandnavigationfilter] 2.475977ms
2016-10-22 08:31:22.927 Jambuster[5669:617846] [CDVTimer][gesturehandler] 0.087976ms
2016-10-22 08:31:22.965 Jambuster[5669:617846] [CDVTimer][splashscreen] 37.754953ms
2016-10-22 08:31:22.966 Jambuster[5669:617846] [CDVTimer][localnotification] 0.499010ms
2016-10-22 08:31:22.966 Jambuster[5669:617846] [CDVTimer][localnotification] 0.015974ms
2016-10-22 08:31:22.966 Jambuster[5669:617846] [CDVTimer][uniquedeviceid] 0.093997ms
2016-10-22 08:31:22.967 Jambuster[5669:617846] [CDVTimer][keyboard] 0.780046ms
2016-10-22 08:31:22.968 Jambuster[5669:617846] [CDVTimer][backgroundfetch] 0.142992ms
2016-10-22 08:31:22.968 Jambuster[5669:617846] [CDVTimer][TotalPluginStartup] 44.156969ms
2016-10-22 08:31:22.974 Jambuster[5669:617846] [PW] [I] -[PushNotificationManager] Will show push notifications alert: 1
2016-10-22 08:31:23.137 Jambuster[5669:617846] [PW] [I] -[PWPushNotificationsManagerCommon] Registered for push notifications: 502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2
2016-10-22 08:31:23.140 Jambuster[5669:617846] Exec: evalling: try{cordova.require('cordova/exec').nativeEvalAndFetch(function(){cordova.fireDocumentEvent('active');})}catch(e){console.log('exeption nativeEvalAndFetch : '+e
2016-10-22 08:31:23.197 Jambuster[5669:617846] Resetting plugins due to page load.
2016-10-22 08:31:23.477 Jambuster[5669:617846] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/getInApps
| Payload:  {"request":{"device_type":1,"language":"en","application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":{"inApps":[]}}
x
2016-10-22 08:31:23.558 Jambuster[5669:617846] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/registerUser
| Payload:  {"request":{"device_type":1,"application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code": 200, "status_message": "OK","response":null}
x
2016-10-22 08:31:24.577 Jambuster[5669:617846] Finished load of: file:///private/var/mobile/Containers/Bundle/Application/6E79EF5E-CB56-4F82-82A2-5E99253DBA2F/Jambuster.app/www/index.html#/tab/summary
2016-10-22 08:31:24.762 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:24.762 Jambuster[5669:617846] Exec(Device1578280555): Calling Device.getDeviceInfo
2016-10-22 08:31:24.763 Jambuster[5669:617846] Exec(Device1578280555): Sending result. Status=1
2016-10-22 08:31:24.763 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('Device1578280555',1,{"manufacturer":"Apple","platform":"iOS","model":"iPhone6,2","uuid":"257B5BB6-D9C9-421E-A125
2016-10-22 08:31:24.770 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:24.770 Jambuster[5669:617846] Exec(NetworkStatus1578280556): Calling NetworkStatus.getConnectionInfo
2016-10-22 08:31:24.773 Jambuster[5669:617846] Exec(NetworkStatus1578280556): Sending result. Status=1
2016-10-22 08:31:24.773 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('NetworkStatus1578280556',1,"wifi",1, 1)
2016-10-22 08:31:24.839 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:24.839 Jambuster[5669:617846] Exec(INVALID): Calling LocalNotification.deviceready
2016-10-22 08:31:24.839 Jambuster[5669:617846] Exec(INVALID): Calling Keyboard.disableScroll
2016-10-22 08:31:24.840 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:24.840 Jambuster[5669:617846] CL BACKLOG:[ 0] 22/10/2016 @ 08:31:24 <<< $ionicPlatform.ready >>>
2016-10-22 08:31:24.841 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:24.841 Jambuster[5669:617846] RegisterAndGetUUID function called
2016-10-22 08:31:24.841 Jambuster[5669:617846] Exec(Keychain1578280557): Calling Keychain.getForKey
2016-10-22 08:31:24.851 Jambuster[5669:617878] Exec(Keychain1578280557): Sending result. Status=1
2016-10-22 08:31:24.851 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('Keychain1578280557',1,"D26FBAF1-2EF2-4614-875F-4497EC4212D5\/JFL1-0\/ios_app",0, 1)
2016-10-22 08:31:24.867 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:24.868 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:24.868 Jambuster[5669:617846] RegisterAndGetPushWooshNotificationIDS called. UUID=D26FBAF1-2EF2-4614-875F-4497EC4212D5/JFL1-0/ios_app
2016-10-22 08:31:24.868 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:24.869 Jambuster[5669:617846] RegisterAndGetPushWooshNotificationIDS: Kicking off pushNotification = cordova.require('pushwoosh-cordova-plugin.PushNotification');
2016-10-22 08:31:24.869 Jambuster[5669:617846] Exec(INVALID): Calling PushNotification.onDeviceReady
2016-10-22 08:31:24.871 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:24.871 Jambuster[5669:617846] Now registering device
2016-10-22 08:31:24.871 Jambuster[5669:617846] Exec(PushNotification1578280558): Calling PushNotification.registerDevice
2016-10-22 08:31:24.872 Jambuster[5669:617846] Exec(PushNotification1578280558): Sending result. Status=0
2016-10-22 08:31:24.873 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('PushNotification1578280558',0,null,1, 1)
2016-10-22 08:31:24.881 Jambuster[5669:617846] [PW] [I] -[PWPushNotificationsManagerCommon] Registered for push notifications: 502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2
2016-10-22 08:31:24.886 Jambuster[5669:617846] Exec(PushNotification1578280558): Sending result. Status=1
2016-10-22 08:31:24.886 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('PushNotification1578280558',1,{"pushToken":"502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2","p
2016-10-22 08:31:24.892 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:24.892 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:24.892 Jambuster[5669:617846] RegisterAndGetPushWooshNotificationIDS: pushNotification.registerDevice status = {"pushToken":"502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2","pushAlert":"1","enabled":"1","type":"7","pushBadge":"1","pushSound":"1"}
2016-10-22 08:31:24.893 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:24.893 Jambuster[5669:617846] RegisterAndGetPushWooshNotificationIDS: notificationIDS = {"userId":"D26FBAF1-2EF2-4614-875F-4497EC4212D5/JFL1-0/ios_app","pushToken":"502504ec6caaf65ab0f3d3d21e2fadc45d874a14a367a24bba9575fb717de6d2"}
2016-10-22 08:31:24.893 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:24.893 Jambuster[5669:617846] RegisterAndGetPushWooshNotificationIDS: Finished setting pushNotification.setMultiNotificationMode
2016-10-22 08:31:24.894 Jambuster[5669:617846] Exec(PushNotification1578280559): Calling PushNotification.getRemoteNotificationStatus
2016-10-22 08:31:24.897 Jambuster[5669:617846] Exec(PushNotification1578280559): Sending result. Status=1
2016-10-22 08:31:24.897 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('PushNotification1578280559',1,{"pushAlert":"1","enabled":"1","type":"7","pushBadge":"1","pushSound":"1"},0, 1)
2016-10-22 08:31:24.898 Jambuster[5669:617846] Exec(INVALID): Calling PushNotification.setApplicationIconBadgeNumber
2016-10-22 08:31:24.902 Jambuster[5669:617846] Exec(INVALID): Sending result. Status=1
2016-10-22 08:31:24.975 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:24.976 Jambuster[5669:617846] Exec(Battery1578280560): Calling Battery.start
2016-10-22 08:31:24.979 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280561): Calling BackgroundGeolocation.configure
🔵-[Settings init] Settings loaded
ℹ️__21-[LocationDAO unlock]_block_invoke UNLOCKED ALL RECORDS
ℹ️-[GeofenceDAO init] CREATE TABLE IF NOT EXISTS geofences (id INTEGER PRIMARY KEY AUTOINCREMENT, identifier TEXT NOT NULL UNIQUE, latitude DOUBLE NOT NULL, sin_latitude DOUBLE NOT NULL, cos_latitude DOUBLE NOT NULL, longitude DOUBLE NOT NULL, sin_longitude DOUBLE NOT NULL, cos_longitude DOUBLE NOT NULL, radius DOUBLE NOT NULL, notifyOnEntry BOOLEAN NOT NULL DEFAULT 0, notifyOnExit BOOLEAN NOT NULL DEFAULT 0, extras TEXT)
ℹ️-[GeofenceDAO init] CREATE index IF NOT EXISTS identifier ON geofences (identifier);CREATE index IF NOT EXISTS latitude ON geofences (latitude);CREATE index IF NOT EXISTS longitude ON geofences (longitude);CREATE index IF NOT EXISTS sin_latitude ON geofences (sin_latitude);CREATE index IF NOT EXISTS cos_latitude ON geofences (cos_latitude);CREATE index IF NOT EXISTS sin_longitude ON geofences (sin_longitude);CREATE index IF NOT EXISTS cos_longitude ON geofences (cos_longitude);
⚠️-[Settings load:] Minimum stationaryRadius is 25

╔═══════════════════════════════════════════════════════════
║ -[TSLocationManager setConfig:] 
{
    activityRecognitionInterval = 10000;
    activityType = 4;
    autoSync = 0;
    autoSyncThreshold = 0;
    batchSync = 1;
    debug = 0;
    desiredAccuracy = "-1";
    disableElasticity = 0;
    disableMotionActivityUpdates = 0;
    disableStopDetection = 0;
    distanceFilter = 20;
    enabled = 1;
    extras =     {
        UUID = "D26FBAF1-2EF2-4614-875F-4497EC4212D5/JFL1-0/ios_app";
    };
    headers = 0;
    heartbeatInterval = 60;
    isMoving = 0;
    locationAuthorizationRequest = Always;
    locationTimeout = 60;
    maxBatchSize = "-1";
    maxDaysToPersist = 1;
    maxRecordsToPersist = "-1";
    method = POST;
    minimumActivityRecognitionConfidence = 70;
    params = 0;
    pausesLocationUpdatesAutomatically = 0;
    preventSuspend = 0;
    schedule = 0;
    schedulerEnabled = 0;
    startOnBoot = 0;
    stationaryRadius = 25;
    stopAfterElapsedMinutes = "-1";
    stopDetectionDelay = 1;
    stopOnTerminate = 1;
    stopTimeout = 60;
    url = "<<REDACTED>><<REDACTED>>";
    useSignificantChangesOnly = 0;
}
╚═══════════════════════════════════════════════════════════
2016-10-22 08:31:25.430 Jambuster[5669:617846] - TSBackgroundFetch addListener: TSLocationManager
2016-10-22 08:31:25.431 Jambuster[5669:617846] - TSBackgroundFetch started
2016-10-22 08:31:25.432 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280561): Sending result. Status=1
2016-10-22 08:31:25.432 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280561',1,{"autoSyncThreshold":0,"distanceFilter":20,"pausesLocationUpdatesAutomaticall
2016-10-22 08:31:25.433 Jambuster[5669:617846] THREAD WARNING: ['BackgroundGeolocation'] took '60.072754' ms. Plugin should use a background thread.
2016-10-22 08:31:25.434 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280562): Calling BackgroundGeolocation.addLocationListener
2016-10-22 08:31:25.435 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280563): Calling BackgroundGeolocation.addHttpListener
2016-10-22 08:31:25.435 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280564): Calling BackgroundGeolocation.addMotionChangeListener
2016-10-22 08:31:25.436 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280565): Calling BackgroundGeolocation.addActivityChangeListener
2016-10-22 08:31:25.437 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280566): Calling BackgroundGeolocation.start
2016-10-22 08:31:25.437 Jambuster[5669:617846] Exec(INVALID): Calling Insomnia.keepAwake
2016-10-22 08:31:25.438 Jambuster[5669:617846] Exec(INVALID): Sending result. Status=1
2016-10-22 08:31:25.438 Jambuster[5669:617846] Exec(LocalNotification1578280567): Calling LocalNotification.getAll
2016-10-22 08:31:25.438 Jambuster[5669:617846] Exec(LocalNotification1578280568): Calling LocalNotification.getAll
2016-10-22 08:31:25.439 Jambuster[5669:617846] Exec(INVALID): Calling PushNotification.setApplicationIconBadgeNumber
2016-10-22 08:31:25.442 Jambuster[5669:617846] Exec(INVALID): Sending result. Status=1
2016-10-22 08:31:25.442 Jambuster[5669:617869] Exec(LocalNotification1578280567): Sending result. Status=1
2016-10-22 08:31:25.443 Jambuster[5669:617877] Exec(LocalNotification1578280568): Sending result. Status=1
2016-10-22 08:31:25.462 Jambuster[5669:617846] THREAD WARNING: ['PushNotification'] took '23.359863' ms. Plugin should use a background thread.
2016-10-22 08:31:25.463 Jambuster[5669:617846] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/applicationOpen
| Payload:  {"request":{"userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","app_version":"1.6.7","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A","language":"en","os_version":"8.3","package":"<<REDACTED>>","v":"4.1.6","application":"<<REDACTED>>","device_type":1,"jailbroken":0,"device_model":"iPhone6,2"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-22 08:31:25.470 Jambuster[5669:617846] [PW] [D] __34-[PWDataManagerCommon] sending appOpen completed
2016-10-22 08:31:25.502 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280566): Sending result. Status=1
2016-10-22 08:31:25.503 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('LocalNotification1578280567',1,[],0, 1)
2016-10-22 08:31:25.504 Jambuster[5669:617846] Exec(Badge1578280569): Calling Badge.clearBadge
2016-10-22 08:31:25.505 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:25.505 Jambuster[5669:617846] AddToExecutionQueue: [{"functionName":"GetNotificationsFromServer","functionArgs":null}]
2016-10-22 08:31:25.505 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:25.506 Jambuster[5669:617846] AddToExecutionQueue: executionQueueTimeout = 61
2016-10-22 08:31:25.506 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:25.508 Jambuster[5669:617870] Exec(Badge1578280569): Sending result. Status=1
2016-10-22 08:31:25.525 Jambuster[5669:617846] RegisterAndGetPushWooshNotificationIDS: getRemoteNotificationStatus = {"pushAlert":"1","enabled":"1","type":"7","pushBadge":"1","pushSound":"1"}
2016-10-22 08:31:25.527 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('LocalNotification1578280568',1,[],0, 1)
2016-10-22 08:31:25.528 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280566',1,true,0, 1)
2016-10-22 08:31:25.537 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280561): Sending result. Status=1
2016-10-22 08:31:25.538 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280562): Sending result. Status=1
2016-10-22 08:31:25.538 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('Badge1578280569',1,0,0, 1)
2016-10-22 08:31:25.539 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280561',1,{"taskId":8,"location":{"coords":{"speed":0,"longitude":-1.06809033081035,"la
2016-10-22 08:31:25.540 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280562',1,{"taskId":8,"location":{"coords":{"speed":0,"longitude":-1.06809033081035,"la
2016-10-22 08:31:25.540 Jambuster[5669:617846] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":0,"application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-22 08:31:25.544 Jambuster[5669:617846] [PW] [D] __34-[PWDataManagerCommon] setBadges completed
2016-10-22 08:31:25.546 Jambuster[5669:617846] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":1,"application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-22 08:31:25.548 Jambuster[5669:617846] [PW] [D] __34-[PWDataManagerCommon] setBadges completed
2016-10-22 08:31:25.578 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280561): Sending result. Status=1
2016-10-22 08:31:25.578 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280562): Sending result. Status=1
2016-10-22 08:31:25.579 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280561',1,{"taskId":9,"location":{"coords":{"speed":-1,"longitude":-1.068090275079132,"
2016-10-22 08:31:25.587 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280562',1,{"taskId":9,"location":{"coords":{"speed":-1,"longitude":-1.068090275079132,"
2016-10-22 08:31:25.588 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280561): Sending result. Status=1
2016-10-22 08:31:25.589 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280562): Sending result. Status=1
2016-10-22 08:31:25.589 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280561',1,{"taskId":10,"location":{"coords":{"speed":-1,"longitude":-1.068089619904448,
2016-10-22 08:31:25.590 Jambuster[5669:617870] Exec(BackgroundGeolocation1578280565): Sending result. Status=1
2016-10-22 08:31:25.591 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280562',1,{"taskId":10,"location":{"coords":{"speed":-1,"longitude":-1.068089619904448,
2016-10-22 08:31:25.592 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280565',1,"still",1, 1)
2016-10-22 08:31:25.738 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280561): Sending result. Status=1
2016-10-22 08:31:25.738 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280562): Sending result. Status=1
2016-10-22 08:31:25.739 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280561',1,{"taskId":11,"location":{"coords":{"speed":-1,"longitude":-1.06793896777874,"
2016-10-22 08:31:25.762 Jambuster[5669:617846] Exec: Retrieved new exec messages by chaining.
2016-10-22 08:31:25.763 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280570): Calling BackgroundGeolocation.changePace
2016-10-22 08:31:25.764 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280570): Sending result. Status=1
2016-10-22 08:31:25.764 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280570',1,true,0, 1)
2016-10-22 08:31:25.765 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280571): Calling BackgroundGeolocation.getCurrentPosition
2016-10-22 08:31:25.765 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280572): Calling BackgroundGeolocation.setConfig
2016-10-22 08:31:25.765 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280573): Calling BackgroundGeolocation.getOdometer
2016-10-22 08:31:25.765 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280573): Sending result. Status=1
2016-10-22 08:31:25.770 Jambuster[5669:617870] Exec(BackgroundGeolocation1578280572): Sending result. Status=1
2016-10-22 08:31:25.771 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280573',1,1136899.73459281,0, 1)
2016-10-22 08:31:25.776 Jambuster[5669:617846] THREAD WARNING: ['BackgroundGeolocation'] took '10.593018' ms. Plugin should use a background thread.
2016-10-22 08:31:25.777 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280562',1,{"taskId":11,"location":{"coords":{"speed":-1,"longitude":-1.06793896777874,"
2016-10-22 08:31:25.777 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:25.777 Jambuster[5669:617846] OPEN database: _pouch_offline-tiles
2016-10-22 08:31:25.778 Jambuster[5669:617846] Exec(SQLitePlugin1578280574): Calling SQLitePlugin.open
2016-10-22 08:31:25.778 Jambuster[5669:617846] Initializing SQLitePlugin
2016-10-22 08:31:25.778 Jambuster[5669:617846] Detected docs path: /var/mobile/Containers/Data/Application/DBB6A04E-9544-484E-B312-DC7E5F85D06C/Documents
2016-10-22 08:31:25.778 Jambuster[5669:617846] Detected Library path: /var/mobile/Containers/Data/Application/DBB6A04E-9544-484E-B312-DC7E5F85D06C/Library
2016-10-22 08:31:25.779 Jambuster[5669:617846] no cloud sync at path: /var/mobile/Containers/Data/Application/DBB6A04E-9544-484E-B312-DC7E5F85D06C/Library/LocalDatabase
2016-10-22 08:31:25.779 Jambuster[5669:617846] open full db path: /var/mobile/Containers/Data/Application/DBB6A04E-9544-484E-B312-DC7E5F85D06C/Documents/_pouch_offline-tiles
2016-10-22 08:31:25.785 Jambuster[5669:617846] Good news: SQLite is thread safe!
2016-10-22 08:31:25.786 Jambuster[5669:617846] Exec(SQLitePlugin1578280574): Sending result. Status=1
2016-10-22 08:31:25.786 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280574',1,"Database opened",0, 1)
2016-10-22 08:31:25.788 Jambuster[5669:617846] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":0,"application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-22 08:31:25.789 Jambuster[5669:617846] [PW] [D] __34-[PWDataManagerCommon] setBadges completed
2016-10-22 08:31:25.827 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280561): Sending result. Status=1
2016-10-22 08:31:25.828 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280562): Sending result. Status=1
2016-10-22 08:31:25.828 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280572',1,null,0, 1)
2016-10-22 08:31:25.829 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:25.829 Jambuster[5669:617846] new transaction is waiting for open operation
2016-10-22 08:31:25.830 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280575): Calling BackgroundGeolocation.finish
2016-10-22 08:31:25.830 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280575): Sending result. Status=1
2016-10-22 08:31:25.830 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280575',1,null,0, 1)
2016-10-22 08:31:25.831 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280561',1,{"taskId":12,"location":{"coords":{"speed":-1,"longitude":-1.06793896777874,"
2016-10-22 08:31:25.831 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280562',1,{"taskId":12,"location":{"coords":{"speed":-1,"longitude":-1.06793896777874,"
2016-10-22 08:31:25.921 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:25.922 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280576): Calling BackgroundGeolocation.getOdometer
2016-10-22 08:31:25.922 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280576): Sending result. Status=1
2016-10-22 08:31:25.922 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280576',1,1136899.73459281,0, 1)
2016-10-22 08:31:25.923 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280577): Calling BackgroundGeolocation.finish
2016-10-22 08:31:25.924 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280577): Sending result. Status=1
2016-10-22 08:31:25.924 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280577',1,null,0, 1)
2016-10-22 08:31:25.925 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280578): Calling BackgroundGeolocation.getOdometer
2016-10-22 08:31:25.925 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280578): Sending result. Status=1
2016-10-22 08:31:25.925 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280578',1,1136899.73459281,0, 1)
2016-10-22 08:31:25.926 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280579): Calling BackgroundGeolocation.finish
2016-10-22 08:31:25.926 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280579): Sending result. Status=1
2016-10-22 08:31:25.927 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280579',1,null,0, 1)
2016-10-22 08:31:25.927 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280580): Calling BackgroundGeolocation.getOdometer
2016-10-22 08:31:25.928 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280580): Sending result. Status=1
2016-10-22 08:31:25.928 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280580',1,1136899.73459281,0, 1)
2016-10-22 08:31:25.928 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280581): Calling BackgroundGeolocation.finish
2016-10-22 08:31:25.929 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280581): Sending result. Status=1
2016-10-22 08:31:25.929 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280581',1,null,0, 1)
2016-10-22 08:31:25.929 Jambuster[5669:617846] Exec(INVALID): Calling Console.logLevel
2016-10-22 08:31:25.929 Jambuster[5669:617846] DB opened: _pouch_offline-tiles
2016-10-22 08:31:25.930 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280582): Calling BackgroundGeolocation.getOdometer
2016-10-22 08:31:25.930 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280582): Sending result. Status=1
2016-10-22 08:31:25.930 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280582',1,1136899.73459281,0, 1)
2016-10-22 08:31:25.931 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280583): Calling BackgroundGeolocation.finish
2016-10-22 08:31:25.931 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280583): Sending result. Status=1
2016-10-22 08:31:25.932 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280583',1,null,0, 1)
2016-10-22 08:31:25.944 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:25.945 Jambuster[5669:617846] Exec(SQLitePlugin1578280584): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:25.946 Jambuster[5669:617870] Exec(SQLitePlugin1578280584): Sending result. Status=1
2016-10-22 08:31:25.946 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280584',1,[{"qid":1111,"type":"success","result":{"rows":[],"rowsAffected":0}},{"qid":1111,"type
2016-10-22 08:31:25.955 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:25.955 Jambuster[5669:617846] Exec(SQLitePlugin1578280585): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:25.956 Jambuster[5669:617871] Exec(SQLitePlugin1578280585): Sending result. Status=1
2016-10-22 08:31:25.957 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280585',1,[{"qid":1111,"type":"success","result":{"rows":[{"sql":"CREATE TABLE 'metadata-store' 
2016-10-22 08:31:25.968 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:25.969 Jambuster[5669:617846] Exec(SQLitePlugin1578280586): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:25.971 Jambuster[5669:617870] Exec(SQLitePlugin1578280586): Sending result. Status=1
2016-10-22 08:31:25.971 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280586',1,[{"qid":1111,"type":"success","result":{"rows":[{"db_version":7}],"rowsAffected":0}}],
2016-10-22 08:31:25.979 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:25.980 Jambuster[5669:617846] Exec(SQLitePlugin1578280587): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:25.980 Jambuster[5669:617892] Exec(SQLitePlugin1578280587): Sending result. Status=1
2016-10-22 08:31:25.981 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280587',1,[{"qid":1111,"type":"success","result":{"rows":[{"dbid":"D42FA880-4620-29FE-BBEE-18053
2016-10-22 08:31:25.986 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:25.987 Jambuster[5669:617846] Exec(SQLitePlugin1578280588): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:25.988 Jambuster[5669:617892] Exec(SQLitePlugin1578280588): Sending result. Status=1
2016-10-22 08:31:25.988 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280588',1,[{"qid":1111,"type":"success","result":{"rows":[],"rowsAffected":0}}],0, 1)
2016-10-22 08:31:26.000 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:26.000 Jambuster[5669:617846] Exec(SQLitePlugin1578280589): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:26.010 Jambuster[5669:617892] Exec(SQLitePlugin1578280589): Sending result. Status=1
2016-10-22 08:31:26.012 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280589',1,[{"qid":1111,"type":"success","result":{"rows":[{"metadata":"{\"id\":\"https:\/\/mapse
2016-10-22 08:31:26.029 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:26.029 Jambuster[5669:617846] Exec(SQLitePlugin1578280590): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:26.036 Jambuster[5669:617871] Exec(SQLitePlugin1578280590): Sending result. Status=1
2016-10-22 08:31:26.038 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280590',1,[{"qid":1111,"type":"success","result":{"rows":[{"metadata":"{\"id\":\"https:\/\/mapse
2016-10-22 08:31:26.061 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:26.061 Jambuster[5669:617846] Exec(SQLitePlugin1578280591): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:26.069 Jambuster[5669:617879] Exec(SQLitePlugin1578280591): Sending result. Status=1
2016-10-22 08:31:26.071 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280591',1,[{"qid":1111,"type":"success","result":{"rows":[{"metadata":"{\"id\":\"https:\/\/mapse
2016-10-22 08:31:26.093 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:26.094 Jambuster[5669:617846] Exec(SQLitePlugin1578280592): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:26.098 Jambuster[5669:617871] Exec(SQLitePlugin1578280592): Sending result. Status=1
2016-10-22 08:31:26.100 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280592',1,[{"qid":1111,"type":"success","result":{"rows":[{"metadata":"{\"id\":\"https:\/\/mapse
2016-10-22 08:31:26.122 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:26.123 Jambuster[5669:617846] Exec(SQLitePlugin1578280593): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:26.126 Jambuster[5669:617879] Exec(SQLitePlugin1578280593): Sending result. Status=1
2016-10-22 08:31:26.128 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280593',1,[{"qid":1111,"type":"success","result":{"rows":[{"metadata":"{\"id\":\"https:\/\/mapse
2016-10-22 08:31:26.156 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:26.157 Jambuster[5669:617846] Exec(SQLitePlugin1578280594): Calling SQLitePlugin.backgroundExecuteSqlBatch
2016-10-22 08:31:26.159 Jambuster[5669:617871] Exec(SQLitePlugin1578280594): Sending result. Status=1
2016-10-22 08:31:26.160 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('SQLitePlugin1578280594',1,[{"qid":1111,"type":"success","result":{"rows":[{"metadata":"{\"id\":\"https:\/\/mapse
2016-10-22 08:31:26.771 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:26.772 Jambuster[5669:617846] Exec(Badge1578280595): Calling Badge.registerPermission
2016-10-22 08:31:26.772 Jambuster[5669:617846] Exec(LocalNotification1578280596): Calling LocalNotification.getAll
2016-10-22 08:31:26.772 Jambuster[5669:617846] Exec(LocalNotification1578280597): Calling LocalNotification.getAll
2016-10-22 08:31:26.773 Jambuster[5669:617846] Exec(INVALID): Calling PushNotification.setApplicationIconBadgeNumber
2016-10-22 08:31:26.777 Jambuster[5669:617846] Exec(INVALID): Sending result. Status=1
2016-10-22 08:31:26.777 Jambuster[5669:617846] Exec(Badge1578280598): Calling Badge.clearBadge
2016-10-22 08:31:26.780 Jambuster[5669:617892] Exec(LocalNotification1578280597): Sending result. Status=1
2016-10-22 08:31:26.780 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('LocalNotification1578280597',1,[],0, 1)
2016-10-22 08:31:26.780 Jambuster[5669:617879] Exec(LocalNotification1578280596): Sending result. Status=1
2016-10-22 08:31:26.781 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('LocalNotification1578280596',1,[],0, 1)
2016-10-22 08:31:26.824 Jambuster[5669:617892] Exec(Badge1578280598): Sending result. Status=1
2016-10-22 08:31:26.824 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('Badge1578280598',1,0,0, 1)
2016-10-22 08:31:26.826 Jambuster[5669:617871] Exec(Badge1578280595): Sending result. Status=1
2016-10-22 08:31:26.832 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('Badge1578280595',1,true,0, 1)
2016-10-22 08:31:26.916 Jambuster[5669:617846] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":1,"application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-22 08:31:26.917 Jambuster[5669:617846] [PW] [D] __34-[PWDataManagerCommon] setBadges completed
2016-10-22 08:31:26.925 Jambuster[5669:617846] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":0,"application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-22 08:31:26.926 Jambuster[5669:617846] [PW] [D] __34-[PWDataManagerCommon] setBadges completed
2016-10-22 08:31:29.290 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:29.290 Jambuster[5669:617846] Exec(INVALID): Calling Badge.setBadge
2016-10-22 08:31:29.293 Jambuster[5669:617871] Exec(INVALID): Sending result. Status=1
2016-10-22 08:31:29.379 Jambuster[5669:617846] [PW] [I] -[PWRequestManager] 
x
|    Pushwoosh request:
| Url:      https://cp.pushwoosh.com/json/1.3/setBadge
| Payload:  {"request":{"device_type":1,"badge":0,"application":"<<REDACTED>>","userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"4.1.6","hwid":"257B5BB6-D9C9-421E-A125-F2B52CFA4F2A"}}
| Status:   "200 no error"
| Response: {"status_code":200,"status_message":"OK","response":null}
x
2016-10-22 08:31:29.380 Jambuster[5669:617846] [PW] [D] __34-[PWDataManagerCommon] setBadges completed
2016-10-22 08:31:30.124 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280561): Sending result. Status=1
2016-10-22 08:31:30.125 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280562): Sending result. Status=1
2016-10-22 08:31:30.127 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280561',1,{"taskId":16,"location":{"coords":{"speed":0,"longitude":-1.067775171251099,"
2016-10-22 08:31:30.129 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280562',1,{"taskId":16,"location":{"coords":{"speed":0,"longitude":-1.067775171251099,"
2016-10-22 08:31:30.281 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:30.281 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280599): Calling BackgroundGeolocation.getOdometer
2016-10-22 08:31:30.282 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280599): Sending result. Status=1
2016-10-22 08:31:30.283 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280599',1,1136899.73459281,0, 1)
2016-10-22 08:31:30.284 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280600): Calling BackgroundGeolocation.finish
2016-10-22 08:31:30.285 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280600): Sending result. Status=1
2016-10-22 08:31:30.286 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280600',1,null,0, 1)
2016-10-22 08:31:31.168 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280561): Sending result. Status=1
2016-10-22 08:31:31.170 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280562): Sending result. Status=1
2016-10-22 08:31:31.171 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280571): Sending result. Status=1
2016-10-22 08:31:31.172 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280561',1,{"taskId":17,"location":{"coords":{"speed":0,"longitude":-1.067775171251099,"
2016-10-22 08:31:31.174 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280562',1,{"taskId":17,"location":{"coords":{"speed":0,"longitude":-1.067775171251099,"
2016-10-22 08:31:31.176 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280571',1,{"taskId":18,"location":{"coords":{"speed":0,"longitude":-1.067775171251099,"
2016-10-22 08:31:31.201 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:31.202 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280601): Calling BackgroundGeolocation.getOdometer
2016-10-22 08:31:31.202 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280601): Sending result. Status=1
2016-10-22 08:31:31.203 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280601',1,1136899.73459281,0, 1)
2016-10-22 08:31:31.204 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280602): Calling BackgroundGeolocation.finish
2016-10-22 08:31:31.205 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280602): Sending result. Status=1
2016-10-22 08:31:31.206 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280602',1,null,0, 1)
2016-10-22 08:31:31.208 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280603): Calling BackgroundGeolocation.finish
2016-10-22 08:31:31.208 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280603): Sending result. Status=1
2016-10-22 08:31:31.209 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280603',1,null,0, 1)
2016-10-22 08:31:38.209 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280561): Sending result. Status=1
2016-10-22 08:31:38.210 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280562): Sending result. Status=1
2016-10-22 08:31:38.211 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280561',1,{"taskId":20,"location":{"coords":{"speed":0,"longitude":-1.067775171251099,"
2016-10-22 08:31:38.214 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280562',1,{"taskId":20,"location":{"coords":{"speed":0,"longitude":-1.067775171251099,"
2016-10-22 08:31:38.220 Jambuster[5669:617940] Exec(BackgroundGeolocation1578280564): Sending result. Status=1
2016-10-22 08:31:38.221 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280564',1,{"isMoving":true,"location":{"coords":{"speed":0,"longitude":-1.0677751712510
2016-10-22 08:31:38.241 Jambuster[5669:617846] Exec: Retrieved new exec messages by chaining.
2016-10-22 08:31:38.242 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280604): Calling BackgroundGeolocation.getOdometer
2016-10-22 08:31:38.243 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280604): Sending result. Status=1
2016-10-22 08:31:38.243 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280604',1,1136899.73459281,0, 1)
2016-10-22 08:31:38.244 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280605): Calling BackgroundGeolocation.finish
2016-10-22 08:31:38.245 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280605): Sending result. Status=1
2016-10-22 08:31:38.246 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280605',1,null,0, 1)
2016-10-22 08:31:38.252 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=0).
2016-10-22 08:31:38.259 Jambuster[5669:617846] Exec: Flushed JS->native queue (hadCommands=1).
2016-10-22 08:31:38.260 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280606): Calling BackgroundGeolocation.finish
2016-10-22 08:31:38.260 Jambuster[5669:617846] Exec(BackgroundGeolocation1578280606): Sending result. Status=1
2016-10-22 08:31:38.261 Jambuster[5669:617846] Exec: evalling: cordova.require('cordova/exec').nativeCallback('BackgroundGeolocation1578280606',1,null,0, 1)

and lastly our list of plugins

com.jcesarmobile.IDFVPlugin 1.0.0 "Identifier For Vendor Plugin" com.rwillett.cordova.plugin.keychainutil 2.0.1 "KeyChain Plugin for Cordova iOS (No iCloud Sync)" com.transistorsoft.cordova.background-geolocation 2.1.0 "BackgroundGeolocation" cordova-plugin-app-event 1.2.0 "Application Events" cordova-plugin-background-fetch 4.0.0 "CDVBackgroundFetch" cordova-plugin-badge 0.7.2 "Badges" cordova-plugin-battery-status 1.1.1 "Battery" cordova-plugin-console 1.0.3 "Console" cordova-plugin-device 1.1.2 "Device" cordova-plugin-dialogs 1.3.0 "Notification" cordova-plugin-insomnia 4.2.0 "Insomnia (prevent screen sleep)" cordova-plugin-network-information 1.1.0 "Network Information" cordova-plugin-splashscreen 3.2.2 "Splashscreen" cordova-plugin-vibration 2.0.0 "Vibration" cordova-plugin-whitelist 1.2.1 "Whitelist" cordova-plugin-x-toast 2.5.1 "Toast" cordova-sqlite-storage 0.7.14 "Cordova sqlite storage plugin" de.appplant.cordova.plugin.local-notification 0.8.4 "LocalNotification" hu.dpal.phonegap.plugins.UniqueDeviceID 1.2.0 "UniqueDeviceID" ionic-plugin-keyboard 2.2.1 "Keyboard" pushwoosh-cordova-plugin 6.2.5 "Pushwoosh"

Hope this helps :)

Rob

[rwillett]

@shaders

Also to be clear, we're NOT using iOS10, we're having this problem with iOS 8. We haven't tried IOS10 very much, indeed this update is to get our app to work on IOS 10. We're testing on IOS8 and IOS8 first.

Rob

[shaders]

@rwillett I might have found a problem.

[rwillett]

Hi,

Have you found a problem or the problem? There's a big semantic difference :)

Rob

[shaders]

All the failed logs have registerDevice API call in the very beginning. This is normal, but I think it breaks registerDevice callback. I'm still investigating.

[rwillett]

Ok, we're working at the moment so if you need any logs, shout and we'll do what we can.

Rob

[shaders]

Could you please change the Pushwoosh file in:

platforms/ios/%projectname%/Plugins/pushwoosh-cordova-plugin/Pushwoosh with this file:

and try again?

[rwillett]

OK, downloaded and rebuilt. The downloaded file is twice the size of the old file.

How do I know its running the new code? Any output to look for?

Up to the 15th run without a hang.

I'll keep going for at least 50 runs :(

[shaders]

It's a debug version. In the log files you should see (in the API requests) version of the SDK as 0.0.

[rwillett]

OK, can see

"userId":"C908C382-6E7C-45E1-B4DD-B26FA952EA99","v":"0.0.0",

30th successful run

[rwillett]

Ok, we've just done 60 consecutive starts without a hang. This is about 40 more than we have managed in the past.

This looks good to me.

Rob

[rwillett]

I suppose the next question is, what other testing is needed and when can a new 'official' build be released?

Rob

[shaders]

I'll push this live Monday

[rwillett]

OK, thanks very much for all the help getting this resolved.

We're back at work and will continue testing today.

[rwillett]

Is 6.2.6 the new version to use for this problem?

Rob

[shaders]

Hi, yes it's 6.2.6 https://github.com/Pushwoosh/pushwoosh-phonegap-plugin/commit/9c6f82495d67afa65f0f3973b5851200297726c6

[zarko-tg]

@shaders Regarding my post at https://github.com/Pushwoosh/pushwoosh-phonegap-plugin/issues/208#issuecomment-255060213 the behaviour hasn't changed with 6.2.6. None of the callback functions of registerDevice are being called. Register -> Unregister -> Register and that's about it where push stops working.

[rwillett]

We haven't tested on iOS 10 yet, only iOS 8 and iOS 9. 6.2.6 works there. However we don't do register and unregister in our app, just the register.

We're out of the office until tomorrow (Weds) and so can't do IOS 10 until then.

Rob

[shaders]

@zarko-tg please see this thread regarding unregister/register, it might be iOS10 bug: https://github.com/Pushwoosh/pushwoosh-unity/issues/18#issuecomment-255362579

[rwillett]

We've now tested on IOS 10 and it seems to work OK.

Rob

[shaders]

👍

[skwasjer]

@shaders @rwillett seems to work for us too