[fixed] tracking "on" but track not recorded

[henryk]

This happened to me today twice on a 5 hours trip. Namely,

0) I turned on the tracker around 15:00
1) the tracker stopped recording on it its own at 16:13 (the last recorded point)
2) I noticed this 20 minutes later and turned the tracker on and off
3) it recorded fine for the next 3 hours
4) again it stopped recording on its own at 19:15
5) the tracker stated that it was "on" when I checked it at 8 pm
6) interestingly, it stayed on even when I closed the application with the back button
7) the icon disappeared when I entered the application again and turned the tracker on and off.

There was very little going on with the phone except of the tracking. I was out of range of data connection, the AlpineQuest was the only application I really used except of
- listening to audio from 15:15 until 17:00,
- sending one text message around 16:30 (this is when I noticed the tracker problem mentioned in 3) and
- making three phone calls from 18:50 until 19:00.

For a moment I was sure that tracking was interrupted by the messaging and phone apps but from the above data unfortunately it is not that simple
I can upload the track, if it is of any help.

[Psyberia-Support]

Hi again,
It seems you have few problems with AlpineQuest and I'm really sorry for that.
The tracker is a really important feature so I am very concerned about it.

First, I don't know if you noticed it, but the tracker runs in a completely different process than AlpineQuest itself. So you can close/kill AlpineQuest while recording a track in background.
This allows the tracker to be a low memory, CPU and battery usage process. On the other hand, communications between AlpineQuest and the tracker is more complex and more subject to bugs.

I often use the tracker myself and never got such a behavior, so it will make this bug more difficult to fix.
Based on your precise description I'll try to figure out what could happened (I'll also try not to move while recording as your suggested in the other thread).

Right now I won't need the GPX file, but I would be very interested by the log files located in the "alpinequest/logs/" folder: "alpinequest.log" and "tracker.log". It would be even greater if you could send them to me just after you noticed that the tracker stopped (before restarting it).

Sorry again for all of that,
Best regards

[henryk]

I am sure that with your attitude it will be possible to fix all the important issues. The tracker problem occured to me also today so I believe that in a day or two I will be able to send you a copy of the the log files before the restart

How should I post the files? I do not see an "attach" button in the forum's options.

[henryk]

OK, here you go This is part I.

Code: Select all

Current date is 2011-12-29
[11:46:23.297] aqControler: entering function 'AlpineQuestControler'
[11:46:23.421] AQSettingsModel: shared preferences are not empty
[11:46:23.421] aqSettingsManager: retrieving application folders...
[11:46:23.424] aqSettingsManager: detected external storage is '/mnt/sdcard'
[11:46:23.424] aqSettingsManager: used external storage is '/sdcard/'
[11:46:23.425] aqSettingsManager: application folder is '/sdcard/alpinequest/'
[11:46:23.500] PsyLogsInstance: log folder has been set to '/sdcard/alpinequest/logs/alpinequest.log'
[11:46:23.500] PsyLogsInstance: nb logs in buffer: 6
[11:46:23.762] aqLandmarks_model: browsed landmarks place 'do_Warszawy_przez_Lodz.gpx'
[11:46:23.940] aqOnlineMapsAqxLoader: entering function 'loadBuiltInAqxFile'
[11:46:24.036] aqMapsModule: entering function '_restoreSettings'
[11:46:24.037] AqAqmMapsSaver: restoring aqm map
[11:46:25.499] AqAqmMapsSaver: previously used aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' restored
[11:46:25.500] aqMapSourceRestorer: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' restored
[11:46:25.531] AqTrackerHandlerControler: entering function 'initialize'
[11:46:25.533] AqTrackerHandlerModel: entering function 'initialize'
[11:46:25.534] AqTrackerHandlerModel: entering function '_retrieveTrackerServiceState'
[11:46:25.544] AqTrackerHandlerModel: tracker service is started
[11:46:25.546] AqTrackerHandlerModel: tracker service is not bound
[11:46:25.549] AqTrackerHandlerCanvasInformation: entering function 'initialize'
[11:46:25.560] AqTrackerHandlerBinder: entering function '_bindTrackerService'
[11:46:25.569] AqTrackerHandlerBinder: callback to 'onServiceConnected'
[11:46:25.569] AqTrackerHandlerModel: entering function '_updateTrackerSettings'
[11:46:25.570] AqTrackerHandlerModel: no activable provider, abording
[11:46:25.570] AqTrackerHandlerModel: entering function '_retrieveTrackerServiceState'
[11:46:25.576] AqTrackerHandlerModel: tracker service is started
[11:46:25.577] AqTrackerHandlerModel: tracker service is bound
[11:46:25.577] AqTrackerHandlerModel: entering function '_loadTrackerDataFromFile'
[11:46:25.601] AqTrackerHandlerBinder: remote function failed: #3
[11:46:25.602] AqTrackerHandlerBinder: didn't get the file lock from tracker service
[11:46:25.674] AqCanvasMapView: detected android api is '10', multitouch activated
[11:46:25.701] aqControler: call to 'onResume'
[11:46:25.701] AqGeolocationService: entering function 'checkHardware'
[11:46:25.705] AqGeolocationServiceProviders: entering function 'retrieveProviders'
[11:46:25.716] AqTrackerHandlerModel: entering function '_updateTrackerSettings'
[11:46:25.717] AqTrackerHandlerBinder: entering function 'callUpdateSettingsFunction(gps, 10, 3.0, 64.0)'
[11:46:25.721] AqTrackerHandlerBinder: remote function failed: #5
[11:46:25.723] AqGeolocationService: starting listening to provider 'gps' (minTime: 10, minDist: 3, threshold: 64.0)
[11:46:25.802] AqCanvasModel: new canvas source loading times: locked=0ms, destroy_old=0ms, init=6ms, listeners=1ms, move=1ms
[11:46:26.810] AqTrackerHandlerBinder: remote function failed: #4
[11:46:26.811] AqTrackerHandlerBinder: didn't get the file unlock from tracker service
[11:46:26.812] AqTrackerHandlerModel: tracker data file successfully loaded
[11:46:26.812] AqTrackerHandlerDataUpdater: entering function 'initialize'
[11:47:31.582] aqControler: call to 'onPause'
[11:47:31.661] AQSettingsModel: entering function '_saveImportantPreferences'
[11:47:31.672] AQSettingsModel: 0 important preference(s) saved
[11:47:31.817] AqAqmMapsSaver: aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[11:47:31.819] aqMapSourceSaver: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[11:57:38.138] aqControler: call to 'onResume'
[11:57:38.151] AqGeolocationService: entering function 'checkHardware'
[11:57:38.159] AqGeolocationServiceProviders: entering function 'retrieveProviders'
[11:57:44.982] AqGeolocationStatusControler: entering function 'initialize'
[11:57:47.645] AqTrackerHandlerModel: entering function 'stopTrackerService'
[11:57:47.663] AqTrackerHandlerBinder: entering function '_unbindTrackerService'
[11:57:47.673] AqTrackerHandlerCanvasInformation: entering function 'destroy'
[11:57:47.686] AqTrackerHandlerModel: entering function '_retrieveTrackerServiceState'
[11:57:47.692] AqTrackerHandlerModel: tracker service is not started
[11:57:47.692] AqTrackerHandlerDataUpdater: entering function 'destroy'
[11:57:47.694] AqTrackerHandlerModel: entering function '_loadTrackerDataFromFile'
[11:57:47.703] AqTrackerHandlerCanvasInformation: entering function 'initialize'
[11:57:48.308] AqTrackerHandlerModel: tracker data file successfully loaded
[11:58:09.949] AqTrackerHandlerDataExporter: entering function '_exportTrackerData'
[11:58:10.181] AqTrackerHandlerModel: entering function 'clearTrackerData'
[11:58:10.190] AqTrackerHandlerCanvasInformation: entering function 'destroy'
[11:58:12.774] AqGeolocationService: stop listening to provider 'gps'
[11:58:16.705] AqGeolocationStatusControler: entering function 'destroy'
[11:58:18.303] aqControler: call to 'onPause'
[11:58:18.307] AQSettingsModel: entering function '_saveImportantPreferences'
[11:58:18.308] AQSettingsModel: 0 important preference(s) saved
[11:58:18.325] AqAqmMapsSaver: aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[11:58:18.327] aqMapSourceSaver: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[11:58:19.084] aqControler: call to 'onFinish'

[henryk]

And this is the tracker log. The time is 12:47 and the tracker is still on

Code: Select all

Current date is 2011-12-29
[11:14:01.754] AlpineQuestTrackerService: callback to 'onCreate'
[11:14:01.756] AlpineQuestTrackerService: callback to 'onStartCommand'
[11:14:01.756] AlpineQuestTrackerService: entering function '_handleCommand'
[11:14:01.764] PsyLogsInstance: log folder has been set to '/sdcard/alpinequest/logs/tracker.log'
[11:14:01.764] PsyLogsInstance: nb logs in buffer: 3
[11:14:01.767] AqTrackerRecorder: entering function 'AqTrackerRecorder'
[11:14:01.769] AqTrackerRecorder: data file path is '/data/data/psyberia.alpinequest.full/files/tracker_locations.tmp' (exists: false, writable: false)
[11:14:02.035] AlpineQuestTrackerService: callback to 'onBind'
[11:14:02.253] AqTrackerBinder: entering function '_functionUpdateSettings'
[11:14:02.254] AqTrackerRecorder: first listening
[11:14:02.255] AqTrackerRecorder: starting listening to provider 'gps' (minTime: 10, minDist: 3.0, threshold: 64.0)
[11:14:04.335] AqTrackerRecorder: got a first fix

[henryk]

I would like to clarify two details:

1. the logs above illustrate the problem with tracker icon remaining on for hours when it should actually be off since approximately 11:58:10.181. The whole track was recorded correctly this time, but I am sure I will find an example as mentioned in the first post, just give me more time

2. despite the fact that the tracker icon was on, the gps was probably turned off. That is, the gps icon disappared when I closed the app at 11:58.

[henryk]

Ok, I have the relevant logs. The tracker was on but the track abruptly ended at 2:14am while I was cycling. I discovered it 30 minutes later. The tracker icon was on but apparently the tracker was not recording anything and gps icon was off. The logs are in 4 parts, that is the .back files and normal logs.

The .alpinequest.log.back file:

Code: Select all

Current date is 2011-12-30
[01:39:41.833] aqControler: entering function 'AlpineQuestControler'
[01:39:41.965] AQSettingsModel: shared preferences are not empty
[01:39:41.966] aqSettingsManager: retrieving application folders...
[01:39:41.971] aqSettingsManager: detected external storage is '/mnt/sdcard'
[01:39:41.972] aqSettingsManager: used external storage is '/sdcard/'
[01:39:41.973] aqSettingsManager: application folder is '/sdcard/alpinequest/'
[01:39:42.063] PsyLogsInstance: log folder has been set to '/sdcard/alpinequest/logs/alpinequest.log'
[01:39:42.063] PsyLogsInstance: nb logs in buffer: 6
[01:39:42.356] aqLandmarks_model: browsed landmarks place 'do_Warszawy_przez_Lodz.gpx'
[01:39:42.575] aqOnlineMapsAqxLoader: entering function 'loadBuiltInAqxFile'
[01:39:42.725] aqMapsModule: entering function '_restoreSettings'
[01:39:42.726] AqAqmMapsSaver: restoring aqm map
[01:39:44.316] AqAqmMapsSaver: previously used aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' restored
[01:39:44.316] aqMapSourceRestorer: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' restored
[01:39:44.328] AqTrackerHandlerControler: entering function 'initialize'
[01:39:44.330] AqTrackerHandlerModel: entering function 'initialize'
[01:39:44.330] AqTrackerHandlerModel: entering function '_retrieveTrackerServiceState'
[01:39:44.339] AqTrackerHandlerModel: tracker service is not started
[01:39:44.340] AqTrackerHandlerModel: entering function '_loadTrackerDataFromFile'
[01:39:44.343] AqTrackerHandlerCanvasInformation: entering function 'initialize'
[01:39:44.459] AqCanvasMapView: detected android api is '10', multitouch activated
[01:39:44.501] aqControler: call to 'onResume'
[01:39:44.502] AqGeolocationService: entering function 'checkHardware'
[01:39:44.507] AqGeolocationServiceProviders: entering function 'retrieveProviders'
[01:39:44.579] AqCanvasModel: new canvas source loading times: locked=0ms, destroy_old=0ms, init=10ms, listeners=5ms, move=0ms
[01:39:45.286] AqTrackerHandlerModel: tracker data file successfully loaded
[01:39:51.212] AqGeolocationStatusControler: entering function 'initialize'
[01:39:56.386] AqTrackerHandlerModel: entering function 'startTrackerService'
[01:39:56.713] AqTrackerHandlerDataUpdater: entering function 'initialize'
[01:39:56.714] AqGeolocationService: starting listening to provider 'gps' (minTime: 10, minDist: 3, threshold: 64.0)
[01:39:56.736] AqTrackerHandlerModel: entering function '_retrieveTrackerServiceState'
[01:39:56.750] AqTrackerHandlerModel: tracker service is started
[01:39:56.755] AqTrackerHandlerModel: tracker service is not bound
[01:39:56.765] AqTrackerHandlerBinder: entering function '_bindTrackerService'
[01:39:56.826] AqTrackerHandlerBinder: callback to 'onServiceConnected'
[01:39:56.828] AqTrackerHandlerModel: entering function '_updateTrackerSettings'
[01:39:56.833] AqTrackerHandlerBinder: entering function 'callUpdateSettingsFunction(gps, 10, 3.0, 64.0)'
[01:39:56.838] AqTrackerHandlerModel: entering function '_retrieveTrackerServiceState'
[01:39:56.841] AqTrackerHandlerModel: tracker service is started
[01:39:56.842] AqTrackerHandlerModel: tracker service is bound
[01:39:56.843] AqTrackerHandlerModel: entering function '_loadTrackerDataFromFile'
[01:39:56.846] AqTrackerHandlerModel: tracker data already loaded
[01:39:58.929] AqGeolocationStatusControler: entering function 'destroy'
[01:40:03.734] aqControler: call to 'onPause'
[01:40:03.734] AQSettingsModel: entering function '_saveImportantPreferences'
[01:40:03.735] AQSettingsModel: 0 important preference(s) saved
[01:40:03.856] AqAqmMapsSaver: aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[01:40:03.859] aqMapSourceSaver: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[02:12:33.255] aqControler: call to 'onResume'
[02:12:33.369] AqGeolocationService: entering function 'checkHardware'
[02:12:33.371] AqGeolocationServiceProviders: entering function 'retrieveProviders'
[02:12:49.735] aqControler: call to 'onPause'
[02:12:49.767] AQSettingsModel: entering function '_saveImportantPreferences'
[02:12:49.770] AQSettingsModel: 0 important preference(s) saved
[02:12:49.862] AqAqmMapsSaver: aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[02:12:49.863] aqMapSourceSaver: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved

A moment later the tracking stopped. That is the blue line ends abruptly with an adnotation 02:14.

The .tracker.log.back.file:

Code: Select all

Current date is 2011-12-29
[22:08:29.238] AlpineQuestTrackerService: callback to 'onCreate'
[22:08:29.240] AlpineQuestTrackerService: callback to 'onStartCommand'
[22:08:29.240] AlpineQuestTrackerService: entering function '_handleCommand'
[22:08:29.264] PsyLogsInstance: log folder has been set to '/sdcard/alpinequest/logs/tracker.log'
[22:08:29.264] PsyLogsInstance: nb logs in buffer: 3
[22:08:29.266] AqTrackerRecorder: entering function 'AqTrackerRecorder'
[22:08:29.267] AqTrackerRecorder: data file path is '/data/data/psyberia.alpinequest.full/files/tracker_locations.tmp' (exists: false, writable: false)
[22:08:29.463] AlpineQuestTrackerService: callback to 'onBind'
[22:08:29.581] AqTrackerBinder: entering function '_functionUpdateSettings'
[22:08:29.582] AqTrackerRecorder: first listening
[22:08:29.582] AqTrackerRecorder: starting listening to provider 'gps' (minTime: 10, minDist: 3.0, threshold: 64.0)
[22:08:34.993] AqTrackerRecorder: got a first fix
[22:29:33.915] AlpineQuestTrackerService: callback to 'onDestroy'
[22:29:33.918] AqTrackerRecorder: stop listening to provider
[22:29:34.033] AqTrackerRecorder: last locations flushed
[22:29:34.061] PsyLogsInstance: closing log file

The alpinequest.log file:

Code: Select all

Current date is 2011-12-30
[02:33:47.483] aqControler: entering function 'AlpineQuestControler'
[02:33:47.748] AQSettingsModel: shared preferences are not empty
[02:33:47.749] aqSettingsManager: retrieving application folders...
[02:33:47.769] aqSettingsManager: detected external storage is '/mnt/sdcard'
[02:33:47.769] aqSettingsManager: used external storage is '/sdcard/'
[02:33:47.769] aqSettingsManager: application folder is '/sdcard/alpinequest/'
[02:33:47.876] PsyLogsInstance: log folder has been set to '/sdcard/alpinequest/logs/alpinequest.log'
[02:33:47.879] PsyLogsInstance: nb logs in buffer: 6
[02:33:48.269] aqLandmarks_model: browsed landmarks place 'do_Warszawy_przez_Lodz.gpx'
[02:33:48.520] aqOnlineMapsAqxLoader: entering function 'loadBuiltInAqxFile'
[02:33:48.675] aqMapsModule: entering function '_restoreSettings'
[02:33:48.676] AqAqmMapsSaver: restoring aqm map
[02:33:50.345] AqAqmMapsSaver: previously used aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' restored
[02:33:50.346] aqMapSourceRestorer: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' restored
[02:33:50.396] AqTrackerHandlerControler: entering function 'initialize'
[02:33:50.397] AqTrackerHandlerModel: entering function 'initialize'
[02:33:50.398] AqTrackerHandlerModel: entering function '_retrieveTrackerServiceState'
[02:33:50.415] AqTrackerHandlerModel: tracker service is started
[02:33:50.415] AqTrackerHandlerModel: tracker service is not bound
[02:33:50.417] AqTrackerHandlerCanvasInformation: entering function 'initialize'
[02:33:50.418] AqTrackerHandlerBinder: entering function '_bindTrackerService'
[02:33:50.490] AqTrackerHandlerBinder: callback to 'onServiceConnected'
[02:33:50.491] AqTrackerHandlerModel: entering function '_updateTrackerSettings'
[02:33:50.491] AqTrackerHandlerModel: no activable provider, abording
[02:33:50.492] AqTrackerHandlerModel: entering function '_retrieveTrackerServiceState'
[02:33:50.496] AqTrackerHandlerModel: tracker service is started
[02:33:50.496] AqTrackerHandlerModel: tracker service is bound
[02:33:50.497] AqTrackerHandlerModel: entering function '_loadTrackerDataFromFile'
[02:33:50.524] AqTrackerHandlerBinder: remote function failed: #3
[02:33:50.525] AqTrackerHandlerBinder: didn't get the file lock from tracker service
[02:33:50.597] AqCanvasMapView: detected android api is '10', multitouch activated
[02:33:50.651] aqControler: call to 'onResume'
[02:33:50.652] AqGeolocationService: entering function 'checkHardware'
[02:33:50.662] AqGeolocationServiceProviders: entering function 'retrieveProviders'
[02:33:50.696] AqTrackerHandlerModel: entering function '_updateTrackerSettings'
[02:33:50.697] AqTrackerHandlerBinder: entering function 'callUpdateSettingsFunction(gps, 10, 3.0, 64.0)'
[02:33:50.698] AqTrackerHandlerBinder: remote function failed: #5
[02:33:50.702] AqGeolocationService: starting listening to provider 'gps' (minTime: 10, minDist: 3, threshold: 64.0)
[02:33:50.839] AqCanvasModel: new canvas source loading times: locked=0ms, destroy_old=0ms, init=32ms, listeners=1ms, move=0ms
[02:33:52.184] AqTrackerHandlerBinder: remote function failed: #4
[02:33:52.190] AqTrackerHandlerBinder: didn't get the file unlock from tracker service
[02:33:52.206] AqTrackerHandlerModel: tracker data file successfully loaded
[02:33:52.207] AqTrackerHandlerDataUpdater: entering function 'initialize'
[02:34:36.092] aqControler: call to 'onPause'
[02:34:36.115] AQSettingsModel: entering function '_saveImportantPreferences'
[02:34:36.121] AQSettingsModel: 0 important preference(s) saved
[02:34:36.175] AqAqmMapsSaver: aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[02:34:36.176] aqMapSourceSaver: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved

The tracker.log file:

Code: Select all

Current date is 2011-12-30
[01:39:56.506] AlpineQuestTrackerService: callback to 'onCreate'
[01:39:56.507] AlpineQuestTrackerService: callback to 'onStartCommand'
[01:39:56.507] AlpineQuestTrackerService: entering function '_handleCommand'
[01:39:56.516] PsyLogsInstance: log folder has been set to '/sdcard/alpinequest/logs/tracker.log'
[01:39:56.516] PsyLogsInstance: nb logs in buffer: 3
[01:39:56.518] AqTrackerRecorder: entering function 'AqTrackerRecorder'
[01:39:56.519] AqTrackerRecorder: data file path is '/data/data/psyberia.alpinequest.full/files/tracker_locations.tmp' (exists: true, writable: true)
[01:39:56.782] AlpineQuestTrackerService: callback to 'onBind'
[01:39:56.834] AqTrackerBinder: entering function '_functionUpdateSettings'
[01:39:56.835] AqTrackerRecorder: first listening
[01:39:56.835] AqTrackerRecorder: starting listening to provider 'gps' (minTime: 10, minDist: 3.0, threshold: 64.0)
[01:40:09.504] AqTrackerRecorder: got a first fix

[Psyberia-Support]

Hi,
Thanks for this updates.
Do you think you could post (if you still have it) the last "tracker.log" file after it is closed (the one on the 2011-12-30 starting at [01:39:56.506]). It seems that some logs had not been written at that time, last logs being written only when the file log is closed when the tracker stops.

Reading your posted logs, I got a better idea of the problem.
At a precise moment, the tracker, while being still running, stops responding to AlpineQuest, resulting in messages like:
[02:33:50.524] AqTrackerHandlerBinder: remote function failed: #3
at every attempt to talk to the tracker.

This is just after a weird log:
[02:33:50.491] AqTrackerHandlerModel: no activable provider, abording
which seems to say that the GPS is not available at that time. So I made the try to deactivate the GPS (from the Android preferences) while recording a track and got a quite similar result than yours (tracker status icon still running but tracker no more recording). I don't think that's your issue, but anyway I have to handle this case much cleaner (so that the user can know the tracker is no more recording).
Just to be sure, can you check that you don't have any application that could turn off the GPS at some moment? (such a memory cleaner app).

I had to release the new 1.2.10 version yesterday, I didn't change a lot of things concerning the tracker. However I added much more logging message so I could figure more precisely what's happen. I plan to rewrite the communication process between AlpineQuest and the tracker soon in a stronger way. As soon I have done it, or found the problem in the current version, I will publish a new version.

I'm still working on it, thanks for the help you gave me

[henryk]

1. The next time I will make sure that tracker.log is complete.
2. With regard to the running processes, this is what is reported by the settings: settings, swype, audible, listen, tunein radio, alpinequest, mortplayer, google services, maps, blue skies, 186mb used, 114mb free. I am against 'memory cleaning' and hopefully none of the above mentioned processes does memory cleaning on its own, but if you see anything suspected, let me know. For the sake of experiment I am willing to temporary uninstall the application.

[Psyberia-Support]

Hi,
Ok thanks for the answers.
I completely understand your wish to un-install the application. If you don't plan to use the application soon or anymore ask me for a refund, there is no problem.
Best regards

[henryk]

This was a misunderstanding. By "uninstalling application" I meant uninstalling one of the applications running in the background. I am aware that any piece of software has to go through a number of improvements.

[henryk]

Let me provide some more logs.

Code: Select all

01-02 18:10:05.644 I/ActivityManager(  105): Start proc com.google.android.apps.listen for content provider com.google.android.apps.listen/.ListenProvider: pid=13361 uid=10057 gids={1015, 3003}
01-02 18:14:40.738 W/InputManagerService(  105): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@40b18188
01-02 18:14:42.472 I/ActivityManager(  105): Process com.google.android.apps.uploader (pid 12690) has died.
01-02 18:14:42.523 I/ActivityManager(  105): Process com.psyberia.alpinequest.services.tracker (pid 3527) has died.
01-02 18:14:42.523 W/ActivityManager(  105): Scheduling restart of crashed service psyberia.alpinequest.full/com.psyberia.alpinequest.services.tracker.AlpineQuestTrackerService in 5000ms
01-02 18:14:43.652 D/WifiWatchdogService(  105): (android.server.ServerThread) eduroam (00:21:56:cc:e2:10) does not require the watchdog
01-02 18:14:43.804 I/ActivityManager(  105): Start proc com.google.android.apps.uploader for broadcast com.google.android.apps.uploader/.ConnectivityBroadcastReceiver: pid=13968 uid=10023 gids={3003}
01-02 18:14:44.027 I/ActivityManager(  105): Start proc com.google.android.gm for broadcast com.google.android.gm/.downloadprovider.DownloadReceiver: pid=13977 uid=10038 gids={3003, 1015}
01-02 18:14:44.316 I/ActivityManager(  105): Start proc android.process.media for broadcast com.android.providers.downloads/.DownloadReceiver: pid=13986 uid=10024 gids={1015, 2001, 3003}
01-02 18:14:47.531 I/ActivityManager(  105): Start proc com.psyberia.alpinequest.services.tracker for service psyberia.alpinequest.full/com.psyberia.alpinequest.services.tracker.AlpineQuestTrackerService: pid=13999 uid=10103 gids={3003, 1015}

The tracker was restarted as scheduled, but without the gps signal. I am not exactly sure, why this mass killing of processes happened. It seems to me not normal and it is not handled well neither by the tracker nor by the audiobooks player MortPlayer.

[henryk]

Let ma add the following additional crash report

Code: Select all

01-03 14:06:32.105 I/ActivityManager(  105): Start proc com.google.android.apps.maps:LocationFriendService for service com.google.android.apps.maps/com.google.googlenav.friend.reporting.LocationReceiverService: pid=19884 uid=10026 gids={3003, 1015}
01-03 14:06:33.691 I/ActivityManager(  105): Process psyberia.alpinequest.full (pid 13104) has died.
01-03 14:06:33.695 I/WindowManager(  105): WIN DEATH: Window{409d4b38 psyberia.alpinequest.full/psyberia.alpinequest.full.AlpineQuestActivity paused=false}
01-03 14:06:54.121 I/ActivityManager(  105): Process com.psyberia.alpinequest.services.tracker (pid 6387) has died.
01-03 14:06:54.125 W/ActivityManager(  105): Scheduling restart of crashed service psyberia.alpinequest.full/com.psyberia.alpinequest.services.tracker.AlpineQuestTrackerService in 5000ms
01-03 14:06:59.156 I/ActivityManager(  105): Start proc com.psyberia.alpinequest.services.tracker for service psyberia.alpinequest.full/com.psyberia.alpinequest.services.tracker.AlpineQuestTrackerService: pid=19908 uid=10103 gids={3003, 1015}

The background is the following: AlpineQuest was working since around 10:15. The wifi was off. AlpineQuest Tracker survived until 14:06 and managed to record the track. At 14:06 phone was again in the range of wifi and started synchronization. I left the application and a moment later the Tracker crashed during synchrozation. Below are the logs from AlpineQuest.

[henryk]

This is .tracker.log.back

Code: Select all

Current date is 2012-01-03
[10:33:07.737] AlpineQuestTrackerService: callback to 'onCreate'
[10:33:07.741] AlpineQuestTrackerService: callback to 'onStartCommand'
[10:33:07.742] AlpineQuestTrackerService: entering function '_handleCommand'
[10:33:07.974] PsyLogsInstance: log folder has been set to '/sdcard/alpinequest/logs/tracker.log'
[10:33:07.974] PsyLogsInstance: nb logs in buffer: 3
[10:33:08.099] aqTrackerRecorder: entering function 'AqTrackerRecorder'
[10:33:08.103] aqTrackerRecorder: data file path is '/data/data/psyberia.alpinequest.full/files/tracker_locations.tmp' (exists: false, writable: false)
[10:33:08.340] AlpineQuestTrackerService: callback to 'onBind'
[10:33:08.566] aqTrackerBinder: entering function '_functionUpdateSettings'
[10:33:08.567] aqTrackerRecorder: first listening
[10:33:08.570] aqTrackerRecorder: starting listening to provider 'gps' (minTime: 10s, minDist: 3.0m, threshold: 64.0m)
[10:33:11.856] aqTrackerRecorder: got a first fix
[10:37:56.422] aqTrackerRecorder: recorded 26 fixes so far
[10:42:30.444] aqTrackerRecorder: recorded 52 fixes so far
[10:47:03.433] aqTrackerRecorder: recorded 78 fixes so far
[10:48:43.667] aqTrackerBinder: entering function '_functionSetFileLock'
[10:48:43.670] aqTrackerRecorder: data file locked, flush locations
[10:48:43.821] aqTrackerBinder: entering function '_functionUpdateSettings'
[10:48:43.822] aqTrackerRecorder: no need to refresh listening
[10:48:44.125] aqTrackerBinder: entering function '_functionRemoveFileLock'
[10:48:44.125] aqTrackerRecorder: data file unlocked
[10:48:44.125] aqTrackerRecorder: entering function '_flushLockedLocations'
[10:48:44.128] aqTrackerRecorder: pending location(s) to flush: 0
[10:51:48.444] aqTrackerRecorder: recorded 104 fixes so far
[10:57:22.450] aqTrackerRecorder: recorded 130 fixes so far
[11:01:57.496] aqTrackerRecorder: recorded 156 fixes so far
[11:06:38.503] aqTrackerRecorder: recorded 182 fixes so far
[11:12:51.512] aqTrackerRecorder: recorded 208 fixes so far
[11:17:29.501] aqTrackerRecorder: recorded 234 fixes so far
[11:22:13.521] aqTrackerRecorder: recorded 260 fixes so far
[11:23:03.712] aqTrackerBinder: entering function '_functionSetFileLock'
[11:23:03.713] aqTrackerRecorder: data file locked, flush locations
[11:23:03.876] aqTrackerBinder: entering function '_functionUpdateSettings'
[11:23:03.877] aqTrackerRecorder: no need to refresh listening
[11:23:05.932] aqTrackerBinder: entering function '_functionRemoveFileLock'
[11:23:05.932] aqTrackerRecorder: data file unlocked
[11:23:05.933] aqTrackerRecorder: entering function '_flushLockedLocations'
[11:23:05.933] aqTrackerRecorder: pending location(s) to flush: 0
[11:24:06.805] aqTrackerBinder: entering function '_functionSetFileLock'
[11:24:06.861] aqTrackerRecorder: data file locked, flush locations
[11:24:07.385] aqTrackerBinder: entering function '_functionUpdateSettings'
[11:24:07.386] aqTrackerRecorder: no need to refresh listening
[11:24:10.104] aqTrackerBinder: entering function '_functionRemoveFileLock'
[11:24:10.105] aqTrackerRecorder: data file unlocked
[11:24:10.106] aqTrackerRecorder: entering function '_flushLockedLocations'
[11:24:10.106] aqTrackerRecorder: pending location(s) to flush: 0
[13:01:21.662] aqTrackerRecorder: recorded 286 fixes so far
[13:23:18.653] aqTrackerRecorder: recorded 312 fixes so far
[13:42:13.646] aqTrackerRecorder: recorded 338 fixes so far

This is indeed the end. Actually the tracker crashed at 14:06. The tracker icon was still on in the notification bar. I opened and closed the Tracker at 14:32. The application generated a new tracker.log (covering this 1 second of activity) and the old log was moved to .tracker.log.back file.

[henryk]

This is the alpinequest.log for the relevant period of time

Code: Select all

Current date is 2012-01-03
[11:24:02.751] aqControler: entering function 'AlpineQuestControler'
[11:24:03.049] aqSettingsModel: shared preferences are not empty
[11:24:03.050] aqSettingsManager: retrieving application folders...
[11:24:03.050] aqSettingsManager: detected external storage is '/mnt/sdcard'
[11:24:03.051] aqSettingsManager: used external storage is '/sdcard/'
[11:24:03.051] aqSettingsManager: application folder is '/sdcard/alpinequest/'
[11:24:03.182] PsyLogsInstance: log folder has been set to '/sdcard/alpinequest/logs/alpinequest.log'
[11:24:03.183] PsyLogsInstance: nb logs in buffer: 6
[11:24:03.531] aqOnlineMapsAqxLoader: entering function 'loadBuiltInAqxFile'
[11:24:03.734] aqMapsModule: entering function '_restoreSettings'
[11:24:03.743] AqAqmMapsSaver: restoring aqm map
[11:24:06.561] AqAqmMapsSaver: previously used aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' restored
[11:24:06.572] aqMapSourceRestorer: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' restored
[11:24:06.664] aqTrackerHandler: entering function 'initialize'
[11:24:06.666] aqTrackerHandler_model: entering function 'initialize'
[11:24:06.678] aqTrackerHandler_model: entering function '_retrieveTrackerServiceState'
[11:24:06.728] aqTrackerHandler_model: tracker service is started
[11:24:06.729] aqTrackerHandler_model: tracker service is not bound
[11:24:06.738] aqTrackerHandlerCanvasInformation: entering function 'initialize'
[11:24:06.740] aqTrackerHandlerBinder: entering function '_bindTrackerService'
[11:24:06.757] aqTrackerHandlerBinder: callback to 'onServiceConnected'
[11:24:06.758] aqTrackerHandler_model: entering function '_updateTrackerSettings'
[11:24:06.760] aqTrackerHandler_model: no activable provider, abording
[11:24:06.761] aqTrackerHandler_model: entering function '_retrieveTrackerServiceState'
[11:24:06.768] aqTrackerHandler_model: tracker service is started
[11:24:06.775] aqTrackerHandler_model: tracker service is bound
[11:24:06.776] aqTrackerHandler_model: entering function '_loadTrackerDataFromFile'
[11:24:06.871] aqTrackerHandlerBinder: got the file lock from tracker service
[11:24:07.165] aqCanvasMapView: detected android api is '10', multitouch activated
[11:24:07.291] aqControler: call to 'onResume'
[11:24:07.292] aqGeolocationService: entering function 'checkHardware'
[11:24:07.327] aqGeolocationServiceProviders: entering function 'retrieveProviders'
[11:24:07.381] aqTrackerHandler_model: entering function '_updateTrackerSettings'
[11:24:07.384] aqTrackerHandlerBinder: entering function 'callUpdateSettingsFunction(gps, 10, 3.0, 64.0)'
[11:24:07.397] aqGeolocationService: starting listening to provider 'gps' (minTime: 10, minDist: 3, threshold: 64.0)
[11:24:07.547] aqCanvasModel: new canvas source loading times: locked=0ms, destroy_old=0ms, init=21ms, listeners=1ms, move=1ms
[11:24:10.107] aqTrackerHandlerBinder: got the file unlock from tracker service
[11:24:10.497] aqTrackerHandler_model: tracker data file successfully loaded
[11:24:10.498] aqTrackerHandlerDataUpdater: entering function 'initialize'
[11:24:10.912] aqControler: call to 'onPause'
[11:24:11.042] aqSettingsModel: entering function '_saveImportantPreferences'
[11:24:11.050] aqSettingsModel: 0 important preference(s) saved
[11:24:11.333] AqAqmMapsSaver: aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[11:24:11.333] aqMapSourceSaver: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[11:28:27.318] aqControler: call to 'onResume'
[11:28:27.332] aqGeolocationService: entering function 'checkHardware'
[11:28:27.334] aqGeolocationServiceProviders: entering function 'retrieveProviders'
[11:28:31.806] aqControler: call to 'onPause'
[11:28:31.832] aqSettingsModel: entering function '_saveImportantPreferences'
[11:28:31.841] aqSettingsModel: 0 important preference(s) saved
[11:28:31.846] AqAqmMapsSaver: aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[11:28:31.852] aqMapSourceSaver: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[14:05:42.945] aqControler: call to 'onResume'
[14:05:42.954] aqGeolocationService: entering function 'checkHardware'
[14:05:42.954] aqGeolocationServiceProviders: entering function 'retrieveProviders'
[14:05:48.376] aqControler: call to 'onPause'
[14:05:48.400] aqSettingsModel: entering function '_saveImportantPreferences'
[14:05:48.404] aqSettingsModel: 0 important preference(s) saved
[14:05:48.484] AqAqmMapsSaver: aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[14:05:48.487] aqMapSourceSaver: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[14:05:49.464] aqControler: call to 'onResume'
[14:05:49.464] aqGeolocationService: entering function 'checkHardware'
[14:05:49.465] aqGeolocationServiceProviders: entering function 'retrieveProviders'
[14:05:55.134] aqControler: call to 'onPause'
[14:05:55.197] aqSettingsModel: entering function '_saveImportantPreferences'
[14:05:55.197] aqSettingsModel: 0 important preference(s) saved
[14:05:55.213] AqAqmMapsSaver: aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[14:05:55.218] aqMapSourceSaver: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[14:05:55.703] aqControler: call to 'onResume'
[14:05:55.725] aqGeolocationService: entering function 'checkHardware'
[14:05:55.726] aqGeolocationServiceProviders: entering function 'retrieveProviders'
[14:06:01.852] aqControler: call to 'onPause'
[14:06:01.892] aqSettingsModel: entering function '_saveImportantPreferences'
[14:06:01.900] aqSettingsModel: 0 important preference(s) saved
[14:06:01.911] AqAqmMapsSaver: aqm map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved
[14:06:01.916] aqMapSourceSaver: previously used map '/sdcard/alpinequest/maps/Wawa_pln_zach_gm.AQM' saved