search

e-mission / e-mission-docs

Repository for docs and issues. If you need help, please file an issue here. Public conversations are better for open source projects than private email.
https://e-mission.readthedocs.io/en/latest
BSD 3-Clause "New" or "Revised" License
15 stars 34 forks source link

Trips not recorded on iOS #377

Closed MythriNagaraju closed 5 years ago

MythriNagaraju commented 5 years ago

@shankari : After I merged changes to update the sdk to 26 and switch dynamic permissions, the iOS app is not recording trips at all. I also do not see any errors in the XCode log. Is anyone else running into this issue?

shankari commented 5 years ago

@MythriNagaraju none of the changes to update the SDK to 26 applied to iOS, so I have not tested or released a new iOS version. I can't think of any obvious reasons why the plugin updates (the only changes to iOS) should have broken tracking, but you might want to try syncing to tag 2.7.1 (https://github.com/e-mission/e-mission-phone/releases/tag/v2.7.1) and rebuilding on iOS.

That is the version currently in the stores and being tested by users. If that also does not work for you, let me know and I can help you troubleshoot.

MythriNagaraju commented 5 years ago

Thanks @shankari , I'll try doing that. I am using cordova version 8.0.0. Could that be a problem?

shankari commented 5 years ago

@MythriNagaraju I don't think so - the README recommends using cordova 8.0.0 since Jan 2018 https://github.com/e-mission/e-mission-phone/blame/master/README.md#L159 so that is what I must have used to build the working version in the stores.

MythriNagaraju commented 5 years ago

Okay, this time I double checked that the location tracking button was on and both iOS and android apps are recording trips. Although nothing is being logged on the server. I emailed you the log. Would you be able to take a look please? Thanks!

shankari commented 5 years ago

@MythriNagaraju I checked your logs and there was an network error while connecting to the server.

412,1555353367.36028,2019-04-15 11:36:07.360280-07:53,postToHost called with url = /usercache/put -- <redacted>
413,1555353367.37789,2019-04-15 11:36:07.377890-07:53,received response for server_to_phone
414,1555353367.39146,2019-04-15 11:36:07.391460-07:53,"Got error Error Domain=NSURLErrorDomain Code=-1009 ""The Internet connection appears to be offline."" UserInfo={_kCFStreamErrorCodeKey=50, NSUnderlyingError=0x28316b360 {Error Domain=kCFErrorDomainCFNetwork Code=-1009 ""(null)"" UserInfo={_kCFStreamErrorCodeKey=50, _kCFStreamErrorDomainKey=1}}, _NSURLErrorFailingURLSessionTaskErrorKey=LocalDataTask <B7967537-6011-4C6D-86DA-AEC1B3485708>.<1>, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    ""LocalDataTask <B7967537-6011-4C6D-86DA-AEC1B3485708>.<1>""
), NSLocalizedDescription=The Internet connection appears to be offline., NSErrorFailingURLStringKey=<redacted>, NSErrorFailingURLKey=<redacted>, _kCFStreamErrorDomainKey=1} while retrieving data"
415,1555353367.4030302,2019-04-15 11:36:07.403030-07:53,"Got error Error Domain=NSURLErrorDomain Code=-1009 ""The Internet connection appears to be offline."" UserInfo={_kCFStreamErrorCodeKey=50, NSUnderlyingError=0x2831b1fb0 {Error Domain=kCFErrorDomainCFNetwork Code=-1009 ""(null)"" UserInfo={_kCFStreamErrorCodeKey=50, _kCFStreamErrorDomainKey=1}}, _NSURLErrorFailingURLSessionTaskErrorKey=LocalDataTask <8BB727BD-06B0-4842-93C8-1226CF2E1E98>.<1>, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    ""LocalDataTask <8BB727BD-06B0-4842-93C8-1226CF2E1E98>.<1>""
), NSLocalizedDescription=The Internet connection appears to be offline., NSErrorFailingURLStringKey=<redacted>, NSErrorFailingURLKey=<redacted>/usercache/put, _kCFStreamErrorDomainKey=1} while pushing changes to server, retaining data"
416,1555353367.4209301,2019-04-15 11:36:07.420930-07:53,"After clear complete, cache has entries stats/client_nav_event, connection_settings, config/sensor_config, statemachine/transition, background/battery, config/sync_config, stats/client_time, intro_done, config/consent, data_collection_consented_protocol, diary_tutorial_done, background/location, background/filtered_location"
shankari commented 5 years ago

@MythriNagaraju You can check the logs yourself and confirm. There is documentation on how to make the emailed database human readable in

https://github.com/e-mission/e-mission-docs/blob/master/docs/e-mission-phone/troubleshooting_tips_faq.md#reading-the-log-on-your-computer

You can also browse logs using the Profile -> Developer Zone -> Check Log

MythriNagaraju commented 5 years ago

Thank you - I am looking at the .csv file now. I was connected to the server when I force-synced. And force-sync worked from the android app at the same time.

shankari commented 5 years ago

But was your iPhone connected to WiFi or a data plan?

MythriNagaraju commented 5 years ago

Yes!

shankari commented 5 years ago

were you able to access the server (https://....) from safari on the iPhone?

MythriNagaraju commented 5 years ago

Yes, I was able to.

Also, I see this error in the logs while trying to push data to the server:

Error Domain=com.google.HTTPStatus Code=413 ""(null)""

Have you seen this before?

shankari commented 5 years ago

hm, status code 413 is "Payload Too Large" https://developer.mozilla.org/en-US/docs/Web/HTTP/Status/413

That is basically a dup of https://github.com/e-mission/e-mission-docs/issues/283 They were using e-mission behind a reverse proxy, and hadn't bumped up the max request size on the proxy to match the size in e-mission.

They submitted a doc fix (https://github.com/e-mission/e-mission-docs/pull/47) I requested changes, but haven't received a response yet. But you can use the doc fix directly :)

shankari commented 5 years ago

I am not quite sure about why you should be hitting this though. The previous team that ran into this was returning survey results, and our speculation was that the survey result sizes were big. But you are not using surveys. Let me take a closer look.

shankari commented 5 years ago

But you should definitely bump up the max size in the short-term because I know that will fix it.

MythriNagaraju commented 5 years ago

I did bump up the max size in cfc_webapp.py , but that will not work because the server is behind a reverse proxy. I cannot use that doc fix though because in my case the web server is on a windows server and behind a IIS webserver proxy.

MythriNagaraju commented 5 years ago

I am looking into how I can increase request size in IIS webserver proxy

shankari commented 5 years ago

I also took a slightly closer look at this, and there were apparently two failures because of internet connectivity issues.

412,1555353367.36028,2019-04-15 11:36:07.360280-07:53,postToHost called with url = /usercache/put -- https://databucket.lbl.gov
413,1555353367.37789,2019-04-15 11:36:07.377890-07:53,received response for server_to_phone
414,1555353367.39146,2019-04-15 11:36:07.391460-07:53,"Got error Error Domain=NSURLErrorDomain Code=-1009 ""The Internet connection appears to be offline."" 
--
553,1555353809.46131,2019-04-15 11:43:29.461310-07:53,postToHost called with url = /usercache/put -- https://databucket.lbl.gov
554,1555353809.48131,2019-04-15 11:43:29.481310-07:53,received response for server_to_phone
555,1555353809.4922302,2019-04-15 11:43:29.492230-07:53,"Got error Error Domain=NSURLErrorDomain Code=-1009 ""The Internet connection appears to be offline.""

And then after that was resolved, we started getting the 413 error

771,1555355376.78225,2019-04-15 12:09:36.782250-07:53,postToHost called with url = /usercache/put -- https://databucket.lbl.gov
772,1555355376.84644,2019-04-15 12:09:36.846440-07:53,"Got error Error Domain=com.google.HTTPStatus Code=413 ""(null)"" UserInfo={data=<54686520 70616765 20776173 206e6f74 20646973 706c6179 65642062 65636175 73652074 68652072 65717565 73742065 6e746974 79206973 20746f6f 206c6172 67652e>, data_content_type=text/html} while pushing changes to server, retaining data"
773,1555355376.8812802,2019-04-15 12:09:36.881280-07:53,received response for server_to_phone
774,1555355376.88684,2019-04-15 12:09:36.886840-07:53,Got non NULL data while retrieving data

--
794,1555355438.91301,2019-04-15 12:10:38.913010-07:53,postToHost called with url = /usercache/put -- https://databucket.lbl.gov
795,1555355438.97838,2019-04-15 12:10:38.978380-07:53,"Got error Error Domain=com.google.HTTPStatus Code=413 ""(null)"" UserInfo={data=<54686520 70616765 20776173 206e6f74 20646973 706c6179 65642062 65636175 73652074 68652072 65717565 73742065 6e746974 79206973 20746f6f 206c6172 67652e>, data_content_type=text/html} while pushing changes to server, retaining data"
796,1555355439.00019,2019-04-15 12:10:39.000190-07:53,received response for server_to_phone
797,1555355439.0062,2019-04-15 12:10:39.006200-07:53,Got non NULL data while retrieving data

Looking at the actual data sent for the last two calls, we find

769,1555355376.7695,2019-04-15 12:09:36.769500-07:53,159 locationArray + 26 motionEntries = 185 combinedArray
792,1555355438.89831,2019-04-15 12:10:38.898310-07:53,165 locationArray + 28 motionEntries = 193 combinedArray

Those don't seem to be abnormally high. @MythriNagaraju since you are building your own app, you can add a log statement just before sending the data to see the data size. https://github.com/e-mission/cordova-server-communication/blob/master/src/ios/BEMCommunicationHelper.m#L168

MythriNagaraju commented 5 years ago

thanks for looking into this @shankari. I'll try that. So far, I tried bumping up the max size and re-starting the server , but haven't taken any trips since.

shankari commented 5 years ago

@MythriNagaraju you don't need to take any more trips - all the data from your previous trips is still cached in the app. You can try "Force sync" and see if the push works this time.

MythriNagaraju commented 5 years ago

Did not work. Same error again

**CommunicationHelper : Got response org.apache.http.message.BasicHttpResponse@23a5fa6 with statusHTTP/1.1 413 Request Entity Too Large

ServerSyncAdapter : IO Error java.io.IOException while posting converted trips to JSON**

On iOS , I get this error additionally. Fails on this line if (entry.metadata.key == getEndTransition()) {.

I also noticed that the trip ends are not detected correctly on iOS but they are on Android. Is that expected.

MythriNagaraju commented 5 years ago

Could be also related to this ? https://github.com/e-mission/e-mission-docs/issues/333

shankari commented 5 years ago

@MythriNagaraju 

**CommunicationHelper : Got response org.apache.http.message.BasicHttpResponse@23a5fa6 with statusHTTP/1.1 413 Request Entity Too Large

in that case you have not bumped up the max size correctly. Have you bumped up the max size on the reverse proxy? the max size on e-mission should be fine.

On iOS , I get this error additionally. Fails on this line if (entry.metadata.key == getEndTransition()) {.

Well, I don't think that is an additional error. The force sync is failing, and you are getting an error popup. I would defer the investigation of #378 until you get the force sync to actually work.

MythriNagaraju commented 5 years ago

sorry, I meant on Android I don't get an error on Force Sync but on iOS I do.

shankari commented 5 years ago

@MythriNagaraju no I don't think this is related to #333 since according to the iOS documentation, it uses UTF-8 by default. And you are not using a locale that would generate non-ASCII characters. And even if it were, we would get error 500, not error 413.

You just have to figure out how to bump up the max size on your reverse proxy.

shankari commented 5 years ago

@MythriNagaraju a quick way to confirm whether the issue is with the app or with the reverse proxy is to configure the app to connect directly to the e-mission server, skipping the reverse proxy. This may only work when you are on the LBL campus, connected to the local network, but you can use "Force Sync" at work, for example.

shankari commented 5 years ago

@MythriNagaraju if I don't get updates from you on this by EOD, I plan to close this issue since it is not related to the platform in general, but rather to your specific configuration. Apparently, the standard IIS message size is 64kb and there are well known techniques for increasing it, even for specific end points. https://duckduckgo.com/?q=IIS+message+size&t=ffsb&ia=web

MythriNagaraju commented 5 years ago

I still haven't tried connecting to the e-mission-server directly, but I am going to try now. Thank you for that IIS link!

shankari commented 5 years ago

@MythriNagaraju what was the result of the test?

MythriNagaraju commented 5 years ago

I bumped up the size and I no longer get the http 413 error, but I still don't see trips in the usercache on the server. Doing some more testing. Will report back.

MythriNagaraju commented 5 years ago

Now, connection to server is timing out!

MythriNagaraju commented 5 years ago

Trying another config change. Since this is all specific to IIS webserver, if you want , you can close this issue. Or when I get it to work, I can document what worked.

shankari commented 5 years ago

would be great if you could document what worked!

MythriNagaraju commented 5 years ago

I modified the config on the IIS server to increase the max size and I am no longer running into the HTTP 413 error, although now I see a 403 forbidden error. The app server is up and running without any issues. I can also see "inserting entry" in the web server logs. Have you run into this before?

loggerDB (5).withdate.log

shankari commented 5 years ago

@MythriNagaraju "403 forbidden" typically means that the authentication is not working properly. Are your phone and server authentications consistent? Just because you can see "inserting entry" in the web server logs doesn't mean that the data is getting to the server - we also insert entries for the server api time, for example.

You need to look at the messages around auth and the mapping from the email to the uuid at https://github.com/e-mission/e-mission-docs/blob/master/docs/e-mission-server/troubleshooting_tips_FAQ.md

MythriNagaraju commented 5 years ago

@shankari how do I make sure that the phone and server authentications are consistent?

MythriNagaraju commented 5 years ago

@shankari Is there anything in the logs apart from the 403 error that you think is unusual?

loggerDB (7).withdate.log

shankari commented 5 years ago

@MythriNagaraju you should have configured the phone and server authentications using https://github.com/e-mission/e-mission-docs/blob/487edf956bf92c2f8f06647f25e33b7330729e4f/docs/e-mission-both/configuring_authentication.md so you would ensure that you have configured them using the same method...

shankari commented 5 years ago

@MythriNagaraju I would suggest doing further debugging on the server, not the phone.

You need to look at the messages around auth and the mapping from the email to the uuid at https://github.com/e-mission/e-mission-docs/blob/master/docs/e-mission-server/troubleshooting_tips_FAQ.md

MythriNagaraju commented 5 years ago

thanks @shankari . Currently, the auth method in conf/net/api/webserver.conf is "skip" and the auth method in connectionConfig.json is "prompted-auth". Is that correct?

shankari commented 5 years ago

that should be fine (it is basically no authentication). What do you see in

the messages around auth and the mapping from the email to the uuid at https://github.com/e-mission/e-mission-docs/blob/master/docs/e-mission-server/troubleshooting_tips_FAQ.md

MythriNagaraju commented 5 years ago

I see this:

2019-04-30 01:14:13,804:DEBUG:10128:START POST /usercache/get
2019-04-30 01:14:13,805:DEBUG:10128:Called userCache.get
2019-04-30 01:14:13,805:DEBUG:10128:methodName = skip, returning <class 'emission.net.auth.skip.SkipMethod'>
2019-04-30 01:14:13,805:DEBUG:10128:Using the skip method to verify id token my3_apr19_android:5723 of length 22
2019-04-30 01:14:13,807:DEBUG:10128:retUUID = None
2019-04-30 01:14:13,807:DEBUG:10128:END POST /usercache/get None 0.0030012130737304688

It never finds/returns the UUID?

shankari commented 5 years ago

did you register to this server with the username my3_apr19_android:5723 before? (e.g. go through the onboarding successfully?)

If not, please log out and log in again. Also, in case you are doing this, please use different tokens for android and iOS - logging in with the same token can break the analysis since we don't know which data came from which device.

MythriNagaraju commented 5 years ago

That worked @shankari !

2019-04-30 11:32:17,756:DEBUG:2688:START POST /usercache/get
2019-04-30 11:32:17,757:DEBUG:2688:Called userCache.get
2019-04-30 11:32:17,757:DEBUG:2688:methodName = skip, returning <class 'emission.net.auth.skip.SkipMethod'>
2019-04-30 11:32:17,757:DEBUG:2688:Using the skip method to verify id token my3_apr19_android:5733:5723 of length 27
2019-04-30 11:32:17,759:DEBUG:2688:retUUID = 1a62316b-4bdb-4058-a32f-44a39604b036
2019-04-30 11:32:17,759:DEBUG:2688:user_uuid 1a62316b-4bdb-4058-a32f-44a39604b036
2019-04-30 11:32:17,763:DEBUG:2688:END POST /usercache/get 1a62316b-4bdb-4058-a32f-44a39604b036 0.007007122039794922

I am now able to see the 'background/location' entries in the usercache table for that user too. Thanks so much! Going to test on iOS now.

shankari commented 5 years ago

Yay! obviously, in your real deployment, your users would go through the onboarding on the correct server, so this would not be an issue :)

MythriNagaraju commented 5 years ago

Right!

MythriNagaraju commented 5 years ago

@shankari Are the modes of the trips written to any of the tables in the MongoDB database? Or can they be inferred from the data in the tables in any way?

shankari commented 5 years ago

https://github.com/e-mission/e-mission-server#experimenting-with-loaded-data

Also, did you look for prior issues - e.g. https://github.com/e-mission/e-mission-docs/issues/350

shankari commented 5 years ago

closing this for now, since trip recording on iOS has obviously been resolved. Please file a new issue or reopen an existing issue to understand the data access better.

shankari commented 5 years ago

You may also find this useful. shankari_mobility_diary_pipeline_5_1.pdf