Sleep tracking crashes about a quarter into the night about sleep-as-android-garmin-addon

[skros89]

For both builds (september release and current), I only changed that one line. They both ran for around 3 hours of tracking without crashing, whereas before it always crashed after 1 hour. But that was just testing during the day. Tonight I'm gonna test to see if it lasts the whole night, I'll let you know tomorrow.
As to why it happens; I have no idea. I don't have any experience with android development, so unfortunately I won't be much help in finding out either.

[MrFly]

@Artaud Ok, just installed it and started sleep for a first test. The images are nearly the same than before, so this should work without problems. I'll give it a try this night. Tomorrow in the morning I will give feedback about it...

[alexmihaila64]

Ok, i got it working (2 of 3 nights) on my 645m. Key to succes was to revert everything to configuration that worked before latest updates. my curent config is:
GC latest version.
SaA beta from 2018.08.18 (latest have an annoing bug that prevent me to add manual sleep it starts tracking instaed)
SaA Garmin Addon version 20180620 downloaded from APKpure
SaA Garmin start latest version from playstore
Garmin watch app 20180831 extracted from iq file from github, random 53k since i don't know which is which.
Phone memory cleared berore sleep and all battery optimizations for above programs disabled. Then start all programs and sync watch before starting tracking.
It worked 2 nights, in the night that quit after 1 hr, watch app was stiill running in the morning, but i found that SaA Garmin Addon app was not running, maybe it crashed or being killed by system. as soon as i started GA, data started to come again.
So maybe the problem is with Android Garmin Addon.
I will keep my curent config since i am tired to test continuously; In September worked more than 2 weeks every night so it's ok with me.
As a note, the same config is not working on my VAHR, so i remove it from GC
Hope this help
Alex

[skros89]

Ok, I finally narrowed this down a bit. It is related to the internet permissions (AndroidManifest.xml) that is being commented out for the release builds. If I build the current code, or the september release of the garmin addon and leave in the internet permissions it doesn't crash. This was tested using the latest release of the watch app from IQ store and latest SaA from play store.

[aaronjwood]

Just tried this out, all you need to do is create the log file on the device. No need for a debug build. I just created 88G34652.txt in the LOGS folder and ran a super quick sleep tracking event:

1539676388: Registering for Phone Messages
1539676388: Incoming mail: SetAlarm;1539013200000
1539676388: Alarm set to 2147483647
1539676388: Incoming mail: StopApp
1539676389: Message not handledStopApp
1539676389: --onStart--
1539676389: free: 104568
1539676389: Adding to q:STARTING outQ: [STARTING]
1539676389: getInitialView
1539676389: SleepMainView initialize
1539676389: SleepMainDelegate initialize
1539676389: 2
1539676389: onUpdate
1539676389: onUpdate
1539676389: onUpdate
1539676389: Send next message STARTING
1539676389: onUpdate
1539676390: msgQ: []
1539676390: STARTINGsent OK
1539676391: onKey: 8
1539676391: scrollUp
1539676391: Refreshing View
1539676391: onUpdate
1539676392: onKey: 8
1539676392: scrollUp
1539676392: Refreshing View
1539676392: onUpdate
1539676393: onKey: 8
1539676393: scrollUp
1539676393: Refreshing View
1539676393: onUpdate
1539676394: Incoming mail: SetAlarm;1539704400000
1539676394: Alarm set to 2147483647
1539676394: onKey: 8
1539676394: scrollUp
1539676394: Refreshing View
1539676394: onUpdate
1539676397: Incoming mail: StartHRTracking
1539676397: Switched trackingBool to true
1539676397: changed view to tracking
1539676397: onUpdate
1539676401: Incoming mail: StartTracking
1539676405: onKey: 4
1539676405: onSelect
1539676405: returnCentre
1539676405: Refreshing View
1539676405: changed view to tracking
1539676405: onUpdate
1539676405: Incoming mail: Pause;1539677289965
1539676407: onKey: 8
1539676407: scrollUp
1539676407: Refreshing View
1539676407: changed view to tracking
1539676407: onUpdate
1539676408: onKey: 8
1539676408: scrollUp
1539676408: Refreshing View
1539676408: changed view to tracking
1539676408: onUpdate
1539676409: onKey: 4
1539676409: onSelect
1539676409: free: 102000
1539676409: Adding to q:PAUSE outQ: [PAUSE]
1539676409: returnCentre
1539676409: Refreshing View
1539676409: changed view to tracking
1539676409: onUpdate
1539676409: Send next message PAUSE
1539676409: Incoming mail: SetAlarm;1539704400000
1539676409: Alarm set to 2147483647
1539676410: msgQ: []
1539676410: PAUSEsent OK
1539676412: Incoming mail: Pause;1539677589965
1539676412: onKey: 8
1539676412: scrollUp
1539676412: Refreshing View
1539676412: changed view to tracking
1539676412: onUpdate
1539676412: onKey: 8
1539676412: scrollUp
1539676412: Refreshing View
1539676412: changed view to tracking
1539676412: onUpdate
1539676413: onKey: 4
1539676413: onSelect
1539676413: free: 101984
1539676413: Adding to q:PAUSE outQ: [PAUSE]
1539676413: returnCentre
1539676413: Refreshing View
1539676413: changed view to tracking
1539676413: onUpdate
1539676413: Send next message PAUSE
1539676414: msgQ: []
1539676414: PAUSEsent OK
1539676416: onKey: 8
1539676416: scrollUp
1539676416: Refreshing View
1539676416: changed view to tracking
1539676416: onUpdate
1539676416: onKey: 8
1539676416: scrollUp
1539676416: Refreshing View
1539676416: changed view to tracking
1539676416: onUpdate
1539676417: Incoming mail: StartHRTracking
1539676417: onKey: 8
1539676417: scrollUp
1539676417: Refreshing View
1539676417: changed view to tracking
1539676417: onUpdate
1539676418: onKey: 8
1539676418: scrollUp
1539676418: Refreshing View
1539676418: changed view to tracking
1539676418: onUpdate
1539676419: onKey: 13
1539676419: scrollDown
1539676419: Refreshing View
1539676419: changed view to tracking
1539676419: onUpdate
1539676420: onKey: 4
1539676420: onSelect
1539676420: free: 101984
1539676420: Adding to q:RESUME outQ: [RESUME]
1539676420: returnCentre
1539676420: Refreshing View
1539676420: changed view to tracking
1539676420: onUpdate
1539676420: Send next message RESUME
1539676421: Incoming mail: StartTracking
1539676421: msgQ: []
1539676421: RESUMEsent OK
1539676423: Incoming mail: Pause;1539677889965
1539676425: onKey: 8
1539676425: scrollUp
1539676425: Refreshing View
1539676425: changed view to tracking
1539676425: onUpdate
1539676426: onKey: 4
1539676426: onSelect
1539676426: Normal Exit
1539676426: returnCentre
1539676426: Refreshing View
1539676426: changed view to tracking
1539676426: onUpdate
1539676427: STOPPING sent OK
1539676427: Incoming mail: Pause;0
1539676430: Incoming mail: StopApp
1539676430: SleepMainView initialize
1539676430: SleepMainDelegate initialize
1539676430: 2
1539676430: changed view to tracking
1539676430: onUpdate
1539676430: changed view to tracking
1539676430: onUpdate
1539676432: onStop

I'll use the tracker tonight and see what I get in the morning but I'm guessing there might need to be more log statements to catch the issue. Garmin also has this limitation: When any log file exceeds 5kb, it will automatically be archived to <LOGNAME>.BAK, and a new log will be started. Any old .BAK files will be overwritten when the archive occurs, so the max space a log can reach is ~10kb.

[aaronjwood]

Will do! I'll post back tomorrow after a night with the version you posted.

[alexmihaila64]

Same for me on 645m. Actually it was better since watch app did not quit, but it stopped recording or sending HR.
Version before oct 2 worked fine on my watch for more than 2 weeks, than after update crash started to happen. Since i am not good at programming, it's difficult for me to see what was changed in order to revert the changes and have a version whiched worked ok.
Maybe if it's not to much to ask, can someone compile that version to sideload it and test it again?

[MrFly]

@Artaud Here's the crash log from this night:

2700 (vívoactive 3) SW ver: 540
Build Type: RELEASE
Commit:38eeb66ab91c4dbbb90282ab9eea0f28012192aa
ESN: 3961220313
10/18/18 03:41:09
RTL
errnum: 0x800a
r0: 0x000000d5
r1: 0x0000007e
r2: 0x0000007f
r3: 0x0016bf53
r4: 0x00000000
r5: 0x00000000
r6: 0x00000000
r7: 0x00000000
r8: 0x00000000
r9: 0x00000000
r10: 0x00000000
r11: 0x00000000
r12: 0x00000000
r13: 0x00000000
r14: 0x00000000
r15: 0x00000000
r16: 0x00000000
r17: 0x00000000
r18: 0x00000000
r19: 0x00000000
r20: 0x00000000
r21: 0x00000000
r22: 0x00000000
r23: 0x00000000
Stack frame PC, SP: 0x00197fcd, 0x1fff2398
Call Stack - SP at 0x1fff2398:
	0x00198571
	0x0002729f
	0x0013076b
	0x0016bf53
	0x00148129
	0x0016bf53
	0x0016bf53
	0x00148d4b
	0x0016c867
	0x0000f07d
	0x001d3a65
	0x044ec9e1
	0x00148d4b
	0x00148d4b
	0x00025e43
	0x0016c155
	0x0003b8a1
	0x0003a1e1
	0x00025b03
	0x00148d4b
	0x00148d4b
	0x00148bad
	0x00148bad
	0x00149d83
	0x000ff243
	0x00148bad
	0x0010c857
	0x00011985
	0x0010c885
	0x0010c891
	0x0014a01b
	0x0000e075
Uptime: 23668067

Also I found an older (two nights) error in CIQ_LOG:

---
Error: Unhandled Exception
Time: 2018-10-16T19:38:28Z
Part-Number: 006-B2700-00
Firmware-Version: '5.40'
Language-Code: deu
ConnectIQ-Version: 3.0.3
Filename: 201809~1
Appname: Sleep
Message: 'UnexpectedTypeException: Expected Number/Float/Long/Double, given null/Float'
Stack:
  - pc: 0x1000276c
    File: '/home/artaud/prog/urbandroid/source/SleepGarmin/SleepGarmin-watch/source/SleepMainDelegate.mc'
    Line: 55
    Function: onTap
  - pc: 0x30001d0d

[alexmihaila64]

It's an Android app, and i always start it before starting SaA app (in fact i start SaA by pressing setup tracking in addon). On my phone (Huawei Mate 10 Pro), when i bring the history list with previous programs, all programs which are running or are cached show; there i have the option to prevent system to close it by pressing the lock key). The day in which tracking was incomplete, the program was not in the list among the other two, when it worked, all three program are were the list (they are all locked so system will not killed them) .

[gcupic]

mine is set to smart and I've seen the crashes or to be more precise my Garmin Fenix 3 HR SaA app can't close and stops sending sleep data to SaA on my OnePlus 6. Both are running fresh and un-modified SWs and OSs.

[Artaud]

Hmmm...that's really interesting. Can you really confirm @skros89 that the watch app holds for the whole night? Did you change anything else in your build or just this?
The internet permission was never included in any release build, even if earlier we did not observe this issue.
According to Android docs, the internet permission "Allows applications to open network sockets.", I don't see how this might crash the watchapp, but hey, if it works :)
All I can say now is that I have the permission in my build manifest and I'm currently running tracking for about three hours without crash.

[Artaud]

Pushed an attempt at a fix in the last few commits (mainly b1d1d28 but also a52ae9f, 1ba1272, be40d96).

I'm not sure if the issue will be fixed completely as the root cause still eludes me, but we have tested it with @MrFly (VA3) for the past week and the situation with crash after an hour/few hours did not occur even once.

[Artaud]

Thanks, I've posted this stack trace on the Garmin CIQ forums as this is something the Garmin people need to decipher. Link to the thread: https://forums.garmin.com/forum/developers/connect-iq/1411125-watch-app-stops-randomly-after-running-for-1-hour

As far as I know, it is not possible to do debug logs in a release version of the app, so I cannot gather logs from users who download the app via the Connect IQ store.
If you want to do debug logging, you need to sideload the app. Can you build it for yourself? Or I can build it for you if you want.

[aaronjwood]

Sure, I'll build + sideload it. Give me a few weeks and I should hopefully have some logs for you.

[hAmpzter]

Hey. What Watch are you running it on @aaronjwood ?
I'm using a Fenix 5 and are having the same issue. Is it a big task to compile and sideload an application for and Garmin-device? If I could do the same and maybe be able to give some more help..
Edit: I now saw at the top of the log-file that it says that you have a Fenix 5.. Lol! Anyhow question 2 still valid.

[aaronjwood]

I'm using a Fenix 5 as well. I don't think it should be a big task, I just haven't had the time to get to it yet.

[hAmpzter]

Is it the garmind.debug.xml that you need or how do I enable debugging?

[MrFly]

Same issues here with VA3. Can I help you?

[hAmpzter]

I tried with a own compiled app on my watch yesterday but I don't now how to get good logging of the Garmin-eco-system. Do you know @MrFly ?

[MrFly]

I'm sorry, no. Think it has to he enabled in the app (programatically), then there could be many good log files on the watch.

[aaronjwood]

Was thinking we could make use of

Sleep-as-Android-Garmin-Addon/SleepGarmin-watch/source/SleepApp.mc

Line 48 in 6ee44db

// Logs into the /GARMIN/APPS/LOGS/appname.TXT

Need to create the log file yourself though. I'm not seeing an API to create this file, it looks like the user has to go in and create the file manually through USB mode?!?!

[MrFly]

Seems that it is only possible with a manually deployed debug version of the app (comment on the following line)

[aaronjwood]

Yeah, hoping it's as easy as building a debug version, loading it to the watch, and creating the text file for logs.

@Artaud where did you guys find that logs only work in debug builds? I've seen some of the Garmin devs on their forums say that Sys.println() should still work in release builds, it's just on the user to create that log file themselves.

[hAmpzter]

Alright. I'll create it and try this on my device this night! :)

[Artaud]

@aaronjwood That's great - the issue is that the log file name has to be different for every user who downloads the app, it changes every time you download the app, and (I'm not sure about this) will also change with each update.
The way you did it is working perfectly, but not suitable for mass user logging.
But we're on Github here, so yay!

I also have got a wild idea what might be causing some of the issues. Seeing now how much logging is going on in there in the release version, maybe there is a memory leak on some watches when you don't have the log files created.
That said, I've never encountered this issue on my Vivoactive, neither debug nor release build.

[aaronjwood]

Funny you mention that, I was thinking the same thing. The logs I posted last night showed my free memory dipping each time log is called to check the memory. I saw some people on the forums talking about removing printlns to save memory but I didn't see anything about them causing a leak.

I had the app crash on me again last night so I'll post the logs from my watch ASAP.

[Artaud]

Perfect. To remove the logging, the only thing needed is to toggle the debug flag at

Sleep-as-Android-Garmin-Addon/SleepGarmin-watch/source/SleepApp.mc

Line 14 in a947e16

var debug = true; var fakeTransmit = false; var beta = false; var debugAlarm = false;

I've built the .prg for Fenix 5 that would do no logging: https://github.com/urbandroid-team/Sleep-as-Android-Garmin-Addon/blob/master/watch-releases/20180918-debug-Fenix5-nologging.prg

[aaronjwood]

Hmm unfortunately (at least from the logs) it doesn't look like it's a memory issue for me. Here's the .BAK file with the rotated logs:

1539680820: changed view to tracking
1539680820: onUpdate
1539680820: changed view to tracking
1539680820: onUpdate
1539680820: changed view to tracking
1539680820: onUpdate
1539680820: changed view to tracking
1539680820: onUpdate
1539680820: changed view to tracking
1539680820: onUpdate
1539680820: changed view to tracking
1539680820: onUpdate
1539680820: changed view to tracking
1539680820: onUpdate
1539680820: changed view to tracking
1539680820: onUpdate
1539680820: changed view to tracking
1539680820: onUpdate
1539680820: changed view to tracking
1539680821: onUpdate
1539680880: changed view to tracking
1539680880: onUpdate
1539680880: changed view to tracking
1539680880: onUpdate
1539680880: changed view to tracking
1539680880: onUpdate
1539680880: changed view to tracking
1539680880: onUpdate
1539680880: changed view to tracking
1539680880: onUpdate
1539680880: changed view to tracking
1539680880: onUpdate
1539680880: changed view to tracking
1539680880: onUpdate
1539680904: free: 101880
1539680904: Adding to q:[DATA, [32, 40, 39, 44, 40, 39, 52, 44, 44, 36, 44, 43]] outQ: [[DATA, [32, 40, 39, 44, 40, 39, 52, 44, 44, 36, 44, 43]]]
1539680904: free: 101872
1539680904: Adding to q:[DATA_NEW, [1031, 1032, 1032, 1033, 1033, 1031, 1041, 1032, 1032, 1036, 1034, 1034]] outQ: [[DATA, [32, 40, 39, 44, 40, 39, 52, 44, 44, 36, 44, 43]], [DATA_NEW, [1031, 1032, 1032, 1033, 1033, 1031, 1041, 1032, 1032, 1036, 1034, 1034]]]
1539680904: Send next message [DATA, [32, 40, 39, 44, 40, 39, 52, 44, 44, 36, 44, 43]]
1539680905: msgQ: [[DATA_NEW, [1031, 1032, 1032, 1033, 1033, 1031, 1041, 1032, 1032, 1036, 1034, 1034]]]
1539680905: [DATA, [32, 40, 39, 44, 40, 39, 52, 44, 44, 36, 44, 43]]sent OK
1539680905: Send next message [DATA_NEW, [1031, 1032, 1032, 1033, 1033, 1031, 1041, 1032, 1032, 1036, 1034, 1034]]
1539680906: msgQ: []
1539680906: [DATA_NEW, [1031, 1032, 1032, 1033, 1033, 1031, 1041, 1032, 1032, 1036, 1034, 1034]]sent OK
1539680914: free: 102248
1539680914: Adding to q:[HR, 52] outQ: [[HR, 52]]
1539680914: Send next message [HR, 52]
1539680915: msgQ: []
1539680915: [HR, 52]sent OK
1539680940: changed view to tracking
1539680940: onUpdate
1539680940: changed view to tracking
1539680940: onUpdate
1539680940: changed view to tracking
1539680940: onUpdate
1539680940: changed view to tracking
1539680940: onUpdate
1539680940: changed view to tracking
1539680940: onUpdate
1539681000: changed view to tracking
1539681000: onUpdate
1539681000: changed view to tracking
1539681000: onUpdate
1539681000: changed view to tracking
1539681000: onUpdate
1539681000: changed view to tracking
1539681000: onUpdate
1539681000: changed view to tracking
1539681000: onUpdate
1539681000: changed view to tracking
1539681000: onUpdate
1539681000: changed view to tracking
1539681000: onUpdate
1539681000: changed view to tracking
1539681000: onUpdate
1539681000: changed view to tracking
1539681000: onUpdate
1539681000: changed view to tracking
1539681000: onUpdate
1539681025: free: 101880
1539681025: Adding to q:[DATA, [40, 32, 36, 40, 40, 32, 44, 36, 40, 36, 56, 35]] outQ: [[DATA, [40, 32, 36, 40, 40, 32, 44, 36, 40, 36, 56, 35]]]
1539681025: free: 101872
1539681025: Adding to q:[DATA_NEW, [1034, 1028, 1031, 1030, 1031, 1032, 1036, 1029, 1028, 1032, 1032, 1032]] outQ: [[DATA, [40, 32, 36, 40, 40, 32, 44, 36, 40, 36, 56, 35]], [DATA_NEW, [1034, 1028, 1031, 1030, 1031, 1032, 1036, 1029, 1028, 1032, 1032, 1032]]]
1539681025: Send next message [DATA, [40, 32, 36, 40, 40, 32, 44, 36, 40, 36, 56, 35]]
1539681026: msgQ: [[DATA_NEW, [1034, 1028, 1031, 1030, 1031, 1032, 1036, 1029, 1028, 1032, 1032, 1032]]]
1539681026: [DATA, [40, 32, 36, 40, 40, 32, 44, 36, 40, 36, 56, 35]]sent OK
1539681026: Send next message [DATA_NEW, [1034, 1028, 1031, 1030, 1031, 1032, 1036, 1029, 1028, 1032, 1032, 1032]]
1539681027: msgQ: []
1539681027: [DATA_NEW, [1034, 1028, 1031, 1030, 1031, 1032, 1036, 1029, 1028, 1032, 1032, 1032]]sent OK
1539681060: changed view to tracking
1539681060: onUpdate
1539681060: changed view to tracking
1539681060: onUpdate
1539681060: changed view to tracking
1539681060: onUpdate
1539681060: changed view to tracking
1539681060: onUpdate
1539681060: changed view to tracking
1539681060: onUpdate
1539681060: changed view to tracking
1539681060: onUpdate
1539681060: changed view to tracking
1539681060: onUpdate
1539681060: changed view to tracking
1539681060: onUpdate
1539681060: changed view to tracking
1539681060: onUpdate
1539681120: changed view to tracking
1539681120: onUpdate
1539681120: changed view to tracking
1539681120: onUpdate
1539681120: changed view to tracking
1539681120: onUpdate
1539681120: changed view to tracking
1539681120: onUpdate
1539681120: changed view to tracking
1539681120: onUpdate
1539681146: free: 101880
1539681146: Adding to q:[DATA, [40, 44, 40, 32, 36, 40, 43, 52, 32, 40, 36, 35]] outQ: [[DATA, [40, 44, 40, 32, 36, 40, 43, 52, 32, 40, 36, 35]]]
1539681146: free: 101872
1539681146: Adding to q:[DATA_NEW, [1033, 1030, 1033, 1029, 1033, 1032, 1029, 1035, 1030, 1033, 1032, 1029]] outQ: [[DATA, [40, 44, 40, 32, 36, 40, 43, 52, 32, 40, 36, 35]], [DATA_NEW, [1033, 1030, 1033, 1029, 1033, 1032, 1029, 1035, 1030, 1033, 1032, 1029]]]

I wonder if optimizing the logging would help with device battery life. From the above it looks like the app logs all night on every onUpdate call. Here's the regular .TXT file with the most recent logs right before the crash:

1539681146: Send next message [DATA, [40, 44, 40, 32, 36, 40, 43, 52, 32, 40, 36, 35]]
1539681147: msgQ: [[DATA_NEW, [1033, 1030, 1033, 1029, 1033, 1032, 1029, 1035, 1030, 1033, 1032, 1029]]]
1539681147: [DATA, [40, 44, 40, 32, 36, 40, 43, 52, 32, 40, 36, 35]]sent OK
1539681147: Send next message [DATA_NEW, [1033, 1030, 1033, 1029, 1033, 1032, 1029, 1035, 1030, 1033, 1032, 1029]]
1539681148: msgQ: []
1539681148: [DATA_NEW, [1033, 1030, 1033, 1029, 1033, 1032, 1029, 1035, 1030, 1033, 1032, 1029]]sent OK
1539681180: changed view to tracking
1539681180: onUpdate
1539681180: changed view to tracking
1539681180: onUpdate
1539681180: changed view to tracking
1539681180: onUpdate
1539681180: changed view to tracking
1539681180: onUpdate
1539681180: changed view to tracking
1539681180: onUpdate
1539681180: changed view to tracking
1539681180: onUpdate
1539681180: changed view to tracking
1539681180: onUpdate
1539681180: changed view to tracking
1539681180: onUpdate
1539681180: changed view to tracking
1539681180: onUpdate
1539681180: changed view to tracking
1539681180: onUpdate
1539681240: changed view to tracking
1539681240: onUpdate
1539681240: changed view to tracking
1539681240: onUpdate
1539681240: changed view to tracking
1539681240: onUpdate
1539681240: changed view to tracking
1539681240: onUpdate
1539681240: changed view to tracking
1539681240: onUpdate
1539681267: free: 101880
1539681267: Adding to q:[DATA, [32, 44, 40, 40, 36, 40, 48, 36, 36, 44, 36, 64]] outQ: [[DATA, [32, 44, 40, 40, 36, 40, 48, 36, 36, 44, 36, 64]]]
1539681267: free: 101872
1539681267: Adding to q:[DATA_NEW, [1031, 1036, 1030, 1031, 1036, 1032, 1034, 1032, 1029, 1036, 1032, 1038]] outQ: [[DATA, [32, 44, 40, 40, 36, 40, 48, 36, 36, 44, 36, 64]], [DATA_NEW, [1031, 1036, 1030, 1031, 1036, 1032, 1034, 1032, 1029, 1036, 1032, 1038]]]
1539681267: Send next message [DATA, [32, 44, 40, 40, 36, 40, 48, 36, 36, 44, 36, 64]]
1539681267: msgQ: [[DATA_NEW, [1031, 1036, 1030, 1031, 1036, 1032, 1034, 1032, 1029, 1036, 1032, 1038]]]
1539681267: [DATA, [32, 44, 40, 40, 36, 40, 48, 36, 36, 44, 36, 64]]sent OK
1539681268: Send next message [DATA_NEW, [1031, 1036, 1030, 1031, 1036, 1032, 1034, 1032, 1029, 1036, 1032, 1038]]
1539681269: msgQ: []
1539681269: [DATA_NEW, [1031, 1036, 1030, 1031, 1036, 1032, 1034, 1032, 1029, 1036, 1032, 1038]]sent OK
1539681277: free: 102248
1539681277: Adding to q:[HR, 52] outQ: [[HR, 52]]
1539681277: Send next message [HR, 52]
1539681278: msgQ: []
1539681278: [HR, 52]sent OK
1539681300: changed view to tracking
1539681300: onUpdate
1539681300: changed view to tracking
1539681300: onUpdate
1539681300: changed view to tracking
1539681300: onUpdate
1539681300: changed view to tracking
1539681300: onUpdate
1539681300: changed view to tracking
1539681300: onUpdate
1539681360: changed view to tracking
1539681360: onUpdate
1539681360: changed view to tracking
1539681360: onUpdate
1539681360: changed view to tracking
1539681360: onUpdate
1539681360: changed view to tracking
1539681360: onUpdate
1539681360: changed view to tracking
1539681360: onUpdate
1539681360: changed view to tracking
1539681360: onUpdate
1539681360: changed view to tracking
1539681360: onUpdate
1539681360: changed view to tracking
1539681360: onUpdate
1539681360: changed view to tracking
1539681360: onUpdate
1539681360: changed view to tracking
1539681360: onUpdate
1539681387: free: 101896
1539681387: Adding to q:[DATA, [2783, 1671, 47, 309, 43, 59, 47, 43, 51, 51, 47, 55]] outQ: [[DATA, [2783, 1671, 47, 309, 43, 59, 47, 43, 51, 51, 47, 55]]]
1539681387: free: 101888
1539681387: Adding to q:[DATA_NEW, [1659, 1456, 996, 1021, 992, 992, 994, 989, 989, 991, 994, 991]] outQ: [[DATA, [2783, 1671, 47, 309, 43, 59, 47, 43, 51, 51, 47, 55]], [DATA_NEW, [1659, 1456, 996, 1021, 992, 992, 994, 989, 989, 991, 994, 991]]]
1539681387: Send next message [DATA, [2783, 1671, 47, 309, 43, 59, 47, 43, 51, 51, 47, 55]]

But you know what? I had a crash in the watch again. This is from GARMIN/DEBUG/ERR_LOG.BAK:

2697 (fenix 5) SW ver: 1100
Build Type: RELEASE
Commit:9b90c64df0cf6f9498c472ce547c0986c1d446c0
ESN: 3962006839
10/16/18 02:16:28
RTL
errnum: 0x00a
r0: 0x2005b560
r1: 0x000000c4
r2: 0x0000007e
r3: 0x0000007f
r4: 0x000a5dbd
Stack frame PC, SP: 0x000ce22d, 0x2005b168
Call Stack - SP at 0x2005b168:
	0x0007134f
	0x000a5dbd
	0x0008df0d
	0x000a5dbd
	0x000a5dbd
	0x0008eb95
	0x000a6891
	0x0001011d
	0x0000b4bd
	0x00076d81
	0x0008eb95
	0x0008eb95
	0x0008ea25
	0x0008eb95
	0x000200bd
	0x0008ea25
	0x000a5ffd
	0x00028247
	0x00026993
	0x0001fe33
	0x0008eb95
	0x0008ea25
	0x0008ea43
	0x0008fd31
	0x000500d5
	0x0004ff2d
	0x0005e3a3
	0x00011985
	0x0005e3f1
	0x0005e3fd
	0x0008fe17
	0x000e6d27
Uptime: 533715925

The timestamp on that log directly relates to when the sleep app crashed for me. This morning I saw that the app had only tracked about 5% of my night before it crashed and it was around 2:15 AM that the chart showed tracking had stopped. So now the question is how is the sleep app causing the watch to crash internally? @hAmpzter can you check this log file as well to see if your Fenix 5 is internally crashing?

@Artaud wondering if there's an issue with Garmin's CIQ where excessive logging for hours can cause a crash in the underlying system. Maybe they have a leak somewhere themselves...?

[Artaud]

wondering if there's an issue with Garmin's CIQ where excessive logging for hours can cause a crash in the underlying system. Maybe they have a leak somewhere themselves...?

@aaronjwood Exactly, that's what I was thinking, and we could confirm that by testing the non-logging version. I got only a cryptic response from Coleman on the Garmin team when I posted your crash stack trace on the Garmin forum, but it seems that it's not an isolated issue.

I actually thought that when I build a release version of the app (there is a release flag on the compiler), then all logging would be disabled, so these issues wouldn't present themselves. But that does not seem to be the case.

Could you please test the non-logging version tonight on your F5 (up here)?

Big thanks

[MrFly]

@Artaud does this version work with the VA3 too?

[Artaud]

This build is specifically for F5, but the only difference is in image resources so you can try it, it would probably work, but the layout and the launcher icon may be distorted.

…

On 16 Oct 2018 20:09, "Hans" ***@***.***> wrote: @Artaud <https://github.com/Artaud> does this version work with the VA3 too? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#10 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ADuCVlVORDJyOWdQJvA0ovN3D7_LC3vrks5uliDfgaJpZM4XL9tW> .

[MrFly]

Ok. Anything to do, except install this file?

[MrFly]

@Artaud great! I think, you almost got it! The tracking worked till about three o'clock like a charm. That's 4 hours more than before

[aaronjwood]

@MrFly do you have a crash in your GARMIN/DEBUG/ERR_LOG file around the time that tracking stopped working?

[MrFly]

@aaronjwood yes, there is one

2700 (vívoactive 3) SW ver: 540
Build Type: RELEASE
Commit:38eeb66ab91c4dbbb90282ab9eea0f28012192aa
ESN: 3961220313
10/17/18 03:38:50
RTL
errnum: 0x800a
r0: 0x00000090
r1: 0x0000007e
r2: 0x0000007f
r3: 0x0016bf53
r4: 0x00000000
r5: 0x00000000
r6: 0x00000000
r7: 0x00000000
r8: 0x00000000
r9: 0x00000000
r10: 0x00000000
r11: 0x00000000
r12: 0x00000000
r13: 0x00000000
r14: 0x00000000
r15: 0x00000000
r16: 0x00000000
r17: 0x00000000
r18: 0x00000000
r19: 0x00000000
r20: 0x00000000
r21: 0x00000000
r22: 0x00000000
r23: 0x00000000
Stack frame PC, SP: 0x00197fcd, 0x1fff2398
Call Stack - SP at 0x1fff2398:
	0x00198571
	0x0016bf53
	0x001480d7
	0x0002729f
	0x0013076b
	0x0016bf53
	0x00148129
	0x0016bf53
	0x0016bf53
	0x00148d4b
	0x0016c867
	0x00148a0b
	0x0000f07d
	0x044ec9e1
	0x00148d4b
	0x00148d4b
	0x00025e43
	0x0016c155
	0x0003b8a1
	0x0003a1e1
	0x00025b03
	0x00148d4b
	0x00148d4b
	0x00148bad
	0x00148bad
	0x00149d83
	0x000ff243
	0x00148bad
	0x0010c857
	0x00011985
	0x0010c885
	0x0010c891
Uptime: 21545082

[hAmpzter]

Hey. My logs are exactly the same problem as @aaronjwood is having.

Last pieces of SLEEP.BAK:

1539736260: changed view to tracking
1539736260: onUpdate
1539736287: free: 100128
1539736287: Adding to q:[DATA, [3177, 51, 42, 47, 51, 35, 39, 55, 42, 43, 43, 46]] outQ: [[DATA, [3177, 51, 42, 47, 51, 35, 39, 55, 42, 43, 43, 46]]]

And in the: GARMIN\DEBUG\ERR_LOG.BAK:

2697 (fenix 5) SW ver: 1100
Build Type: RELEASE
Commit:9b90c64df0cf6f9498c472ce547c0986c1d446c0
ESN: 3951293740
10/17/18 02:31:29
RTL
errnum: 0x00a
r0: 0x2005b560
r1: 0x00000084
r2: 0x0000007e
r3: 0x0000007f
r4: 0x000a5dbd
Stack frame PC, SP: 0x000ce22d, 0x2005b168
Call Stack - SP at 0x2005b168:
	0x0007134f
	0x000a5dbd
	0x0008df0d
	0x000a5dbd
	0x000a5dbd
	0x0008eb95
	0x000a6891
	0x0006f66b
	0x0000b25b
	0x00076d81
	0x0008eb95
	0x0008eb95
	0x0008ea25
	0x0008eb95
	0x000200bd
	0x0008ea25
	0x000a5ffd
	0x00028247
	0x00026993
	0x0001fe33
	0x0008eb95
	0x0008ea25
	0x0008ea43
	0x0008fd31
	0x000500d5
	0x0004ff2d
	0x0005e3a3
	0x00011985
	0x0005e3f1
	0x0005e3fd
	0x0008fe17
	0x000e6d27
Uptime: 89095622

[aaronjwood]

I crashed again last night using the version posted above. I only made it about 2 hours in so I didn't get much further than usual.

[MrFly]

Good morning, guys. Some new logs for you. @Artaud I've already sent the wearable report and an error report from SaA.

ERR_LOG.TXT:

2700 (vívoactive 3) SW ver: 540
Build Type: RELEASE
Commit:38eeb66ab91c4dbbb90282ab9eea0f28012192aa
ESN: 3961220313
10/19/18 00:22:31
RTL
errnum: 0x800a
r0: 0x000000dc
r1: 0x0000007e
r2: 0x0000007f
r3: 0x0016bf53
r4: 0x00000000
r5: 0x00000000
r6: 0x00000000
r7: 0x00000000
r8: 0x00000000
r9: 0x00000000
r10: 0x00000000
r11: 0x00000000
r12: 0x00000000
r13: 0x00000000
r14: 0x00000000
r15: 0x00000000
r16: 0x00000000
r17: 0x00000000
r18: 0x00000000
r19: 0x00000000
r20: 0x00000000
r21: 0x00000000
r22: 0x00000000
r23: 0x00000000
Stack frame PC, SP: 0x00197fcd, 0x1fff2398
Call Stack - SP at 0x1fff2398:
	0x00198571
	0x0002729f
	0x0013076b
	0x0016bf53
	0x00148129
	0x0016bf53
	0x0016bf53
	0x00148d4b
	0x0016c867
	0x00130099
	0x0000ee41
	0x0013090d
	0x00148d4b
	0x00148d4b
	0x00025e43
	0x0016c155
	0x0003b8a1
	0x0003a1e1
	0x00025b03
	0x00148d4b
	0x00148d4b
	0x00148bad
	0x00148bad
	0x00149d83
	0x000ff243
	0x00148bad
	0x0010c857
	0x00011985
	0x0010c885
	0x0010c891
	0x0014a01b
	0x0000e075
Uptime: 74480733

[hAmpzter]

Hey. I have now made a version without any logging enabled and tried that for two nights. It seems to last just a tiny bit longer, but not much.
I'll try again with a bit different type of logging next.

[MrFly]

@Artaud Should we use this debugging version above for a time or better revert to the release now?

[Artaud]

Same for me on 645m. Actually it was better since watch app did not quit, but it stopped recording or sending HR.
Version before oct 2 worked fine on my watch for more than 2 weeks, than after update crash started to happen. Since i am not good at programming, it's difficult for me to see what was changed in order to revert the changes and have a version whiched worked ok.
Maybe if it's not to much to ask, can someone compile that version to sideload it and test it again?

@alexmihaila64
This one is from 31 Aug, I'm not sure which model it is for since I extracted it from the published .iq package but it should work okay.
sleep-20180831-notsurewhichmodel.zip

Make sure to unzip the file before sideloading. Let me know if it works better for you! I'd be surprised since literally the only thing I added is one line in the manifest, but hey, you never know.

[Artaud]

@Artaud Should we use this debugging version above for a time or better revert to the release now?

Actually what would really help is if anybody would be so suicidal to factory reset their watch, load the release (no other apps) and track for one or two nights. I understand it is a lot to ask, so no pressure!

[MrFly]

How did you notice, that Garmin Addon was not running? I mean, it's an addon, not a standalone app, so it isn't actually "running" at all. I'm only interested in this, maybe I can try your solution with my equipment...

[MrFly]

Ah! Good explanation, thanks.

[skros89]

@Artaud Should we use this debugging version above for a time or better revert to the release now?

Actually what would really help is if anybody would be so suicidal to factory reset their watch, load the release (no other apps) and track for one or two nights. I understand it is a lot to ask, so no pressure!

Did this tonight on the vivoactive 3 (factory reset) and the tracking stopped after one hour. Going to create a log file now and try again.

[MrFly]

Tried the other way tonight and locked the apps including Garmin addon. Changed nothing with the current versions.

[skros89]

Did this tonight on the vivoactive 3 (factory reset) and the tracking stopped after one hour. Going to create a log file now and try again.

Same thing happened the second time around.
GARMIN\DEBUG\ERR_LOG.TXT:

Build Type: RELEASE
Commit:38eeb66ab91c4dbbb90282ab9eea0f28012192aa
ESN: 3962248612
10/23/18 01:08:39
RTL
errnum: 0x800a
r0: 0x00000092
r1: 0x0000007e
r2: 0x0000007f
r3: 0x0016bf53
r4: 0x00000000
r5: 0x00000000
r6: 0x00000000
r7: 0x00000000
r8: 0x00000000
r9: 0x00000000
r10: 0x00000000
r11: 0x00000000
r12: 0x00000000
r13: 0x00000000
r14: 0x00000000
r15: 0x00000000
r16: 0x00000000
r17: 0x00000000
r18: 0x00000000
r19: 0x00000000
r20: 0x00000000
r21: 0x00000000
r22: 0x00000000
r23: 0x00000000
Stack frame PC, SP: 0x00197fcd, 0x1fff2398
Call Stack - SP at 0x1fff2398:
	0x00198571
	0x0002729f
	0x0013076b
	0x0016bf53
	0x00148129
	0x0016bf53
	0x0016bf53
	0x00148d4b
	0x0016c867
	0x0000f07d
	0x0000ffff
	0x044ec9e1
	0x00148d4b
	0x00148d4b
	0x00025e43
	0x0016c155
	0x0003b8a1
	0x0003a1e1
	0x00025b03
	0x00148d4b
	0x00148d4b
	0x00148bad
	0x00148bad
	0x00149d83
	0x000ff243
	0x00148bad
	0x0010c857
	0x00011985
	0x0010c885
	0x0010c891
	0x0014a01b
	0x0000e075
Uptime: 18437299

2700 (vívoactive 3) SW ver: 540
Build Type: RELEASE
Commit:38eeb66ab91c4dbbb90282ab9eea0f28012192aa
ESN: 3962248612
10/23/18 04:45:16
RTL
errnum: 0x800a
r0: 0x00000099
r1: 0x0000007e
r2: 0x0000007f
r3: 0x0016bf53
r4: 0x00000000
r5: 0x00000000
r6: 0x00000000
r7: 0x00000000
r8: 0x00000000
r9: 0x00000000
r10: 0x00000000
r11: 0x00000000
r12: 0x00000000
r13: 0x00000000
r14: 0x00000000
r15: 0x00000000
r16: 0x00000000
r17: 0x00000000
r18: 0x00000000
r19: 0x00000000
r20: 0x00000000
r21: 0x00000000
r22: 0x00000000
r23: 0x00000000
Stack frame PC, SP: 0x00197fcd, 0x1fff2398
Call Stack - SP at 0x1fff2398:
	0x00198571
	0x0002729f
	0x0013076b
	0x0016bf53
	0x00148129
	0x0016bf53
	0x0016bf53
	0x00148d4b
	0x0016c867
	0x00130099
	0x0000f07d
	0x044ec9e1
	0x00148d4b
	0x00148d4b
	0x00025e43
	0x0016c155
	0x0003b8a1
	0x0003a1e1
	0x00025b03
	0x00148d4b
	0x00148d4b
	0x00148bad
	0x00148bad
	0x00149d83
	0x000ff243
	0x00148bad
	0x0010c857
	0x00011985
	0x0010c885
	0x0010c891
	0x0014a01b
	0x0000e075
Uptime: 12996360

And the App's log GARMIN\APPS\LOGS\8AMI0650.TXT:

1540262713: Send next message [DATA_NEW, [941, 941, 935, 940, 935, 935, 936, 936, 954, 949, 944, 946]]
1540262714: msgQ: []
1540262714: [DATA_NEW, [941, 941, 935, 940, 935, 935, 936, 936, 954, 949, 944, 946]]sent OK
1540262716: free: 102272
1540262716: Adding to q:[HR, 71] outQ: [[HR, 71]]
1540262716: Send next message [HR, 71]

[MrFly]

Only an idea: how did you (all) set the hr measurement interval? Mine is set to "always". Is there a difference if it's set to "smart" (don't know how this is labelled in english)

[skros89]

You mean on the watch right? I think I always had it set to smart. After the factory reset it was definitely on smart (default).

[MrFly]

Yes, I meant on the watch. Ok, at least this should not be the problem...

[aaronjwood]

Interesting...so the Android side of the codebase is causing the Garmin side to crash?

[Artaud]

Many thanks, I'm really looking forward to your findings!

[hAmpzter]

Nice finding @skros89 ! I really hope it works!

[skros89]

Ok, now I'm just confused. While I was asleep it crashed again after 1 hour. This morning I started tracking again while awake and it is still tracking for almost 2 hours already.
The only difference I can think of is that when awake I occasionally check my phone, but when asleep it's idle the whole hour before the crash happens.
I suppose another difference might be that the watch sensors detect more movement when I'm awake.

[gcupic]

If it is any help, I believe that the issue in this thread is linked to this one: #12

at sometime somebuddy asked for a fresh system (Garmin on factory). Well, I've just bought the Garmin Fenix 5X Plus and unfortunately the problem was still there even on the out-of-the box garmin :(

[Artaud]

Big thanks for testing @skros89
Can you please post a CIQ_LOG and ERR_LOG? And if you have the watch app log, could you post that as well?
The only thing that comes to my mind is that we're badly handling the shouldExit flag or something connected to it in SleepApp.mc.
But I can't find anything, so maybe adding some logs could help.

[skros89]

Big thanks for testing @skros89
Can you please post a CIQ_LOG and ERR_LOG? And if you have the watch app log, could you post that as well?
The only thing that comes to my mind is that we're badly handling the shouldExit flag or something connected to it in SleepApp.mc.
But I can't find anything, so maybe adding some logs could help.

I think @difficilebambino is right, and #12 is messing with my testing.
In CIQ_LOG the exceptions are from when I tracked while awake, when stopping the tracking I always got the "!CIQ" error on the watch.
Weirdly enough there is no entry for when the supposed crash happened at night (around 1:00) and the ERR_LOG file is empty. I did not actually witness the crash at night, woke up around 3 and the watch app wasn't running anymore. Saw on my phone that it had only one hour of sleep data, so I just assumed it crashed around 1:00.

CIQ_LOG:

Time: 2018-10-30T19:35:16Z
Part-Number: 006-B2700-00
Firmware-Version: '5.50'
Language-Code: eng
ConnectIQ-Version: 3.0.1
Store-Id: e80a4793-f5a3-44c7-bd7f-52a97f5d8310
Store-Version: 22
Filename: 8AMI0650
Appname: Sleep
Message: 'UnexpectedTypeException: Expected Number/Float/Long/Double, given null/Float'
Stack:
  - pc: 0x100012ea
  - pc: 0x30001d19
---
Error: Unhandled Exception
Time: 2018-10-31T09:28:16Z
Part-Number: 006-B2700-00
Firmware-Version: '5.50'
Language-Code: eng
ConnectIQ-Version: 3.0.1
Store-Id: e80a4793-f5a3-44c7-bd7f-52a97f5d8310
Store-Version: 22
Filename: 8AMI0650
Appname: Sleep
Message: 'UnexpectedTypeException: Expected Number/Float/Long/Double, given null/Float'
Stack:
  - pc: 0x100012ea
  - pc: 0x30001d19

[Artaud]

@skros89 could you please also menu > send wearable report from Sleep?

[skros89]

@Artaud I don't see the option anymore. Has it been removed in the latest SaA?

[Artaud]

@skros89 Oh sorry - you did build your own Garmin addon, right? In that case the option wouldn't show up since we check the build signature of the addon in order to show this option.
In that case sending an intent over ADB would be the simplest solution, are you able to do that?

adb shell am broadcast -a com.urbandroid.sleep.watch.REPORT --es USER_COMMENT "any comment"

A share dialog will show up on your phone, please share to your email app and send the email to the prefilled address...thanks a lot...

[skros89]

@Artaud I tried, nothing shows up on the phone and I get the following output:

Broadcasting: Intent { act=com.urbandroid.sleep.watch.REPORT flg=0x400000 pkg=comment (has extras) }
Broadcast completed: result=0

[Artaud]

So you probably had built the addon with the reporting support disabled, which was in the repo for some time a few commits ago. There's no way to get to our report unfortunately :(
We can still take a look at logcat, would you be willing to send me your logcat?
adb logcat > file.txt
Please send it to [email protected] so as not to post it publicly as it can contain some sensitive data. If you are willing to send it to me of course :)

[skros89]

I just looked at the logcat, and for whatever reason there is nothing between yesterday 21:37 and this morning 10:39. But I will clear all the logs and run a test again tonight. If I build the latest commit of the android addon, reporting support will be enabled again right?

Also I think the internet permission just postpones the crash. When looking at the graph, it seems SaA stops receiving movement data about 20 mins in and HR data after about an hour. This is when the crash would usually happen without the internet permission.
With the internet permission enabled it crashes after 3 and a half hours. The vibration must've woken me up and then I stopped the tracking.

Anyway, just let me know what build you'd like me to test and what logs you need and I'll get you the results tomorrow morning.

[Artaud]

If I build the latest commit of the android addon, reporting support will be enabled again right?

Yes, but only through the adb command as the addon wouldn't be signed by our release key, and thus the "send wearable addon" option wouldn't show up. We're changing that for the next release of Sleep as Android we are releasing right now, so it will show up even with your own Garmin Addon build.

[skros89]

I built the latest commit to test last night, but don't have any logs. The adb command just crashes the Garmin Addon. I assume it's because the commons aar (#11) hasn't been updated in this repo. Logcat was no help either, logs from the crash were already overwritten when I woke up this morning.
As for the Garmin logs, nothing new, same as was already posted in this thread. (#10 (comment))

[MrFly]

@Artaud you know since our last tests, that writing a good log file (debug) should not be the issuse for the crashes (right?). Maybe you could prepare a new debugging version with many loggings for us to test? I'm ready to test. I would test the workaround from @skros89 too. Maybe you (one?) could prepare a combined version with the workaround and massive logging enabled... :-)

[skros89]

@MrFly I've been testing my workaround for the past few nights, it just crashes after 1 hour, just like the release version. For some reason it only gets past 1 hour when I test during the day. I have one more idea I'm testing tonight. If that doesn't work I'm going back to the june release for now. That one only crashes after I dismiss the alarm in the morning.
Of course if @Artaud has any ideas/builds for us to test, I'll gladly help out as well.

[MrFly]

@skros89 ok. What is the difference in code comparing the current release and the mentioned june release? Do you have a compare view, which you could share with me?

I've got the strange feeling, that the problem isn't located to the watch app at all... Maybe there are other apps involved. Did you test the current release of the watch app with an older version of the SaA or Garmin addon? If not, I can give it a try these days...

[skros89]

I've got the strange feeling, that the problem isn't located to the watch app at all... Maybe there are other apps involved. Did you test the current release of the watch app with an older version of the SaA or Garmin addon? If not, I can give it a try these days...

@MrFly Yes, I was talking about the Garmin addon june release (apkpure: V20180620). Using the current releases of SaA and the watch app with the june release of the addon, sleep tracking works through the night for me (Vivoactive 3) and only freezes when stopping in the morning.

@skros89 ok. What is the difference in code comparing the current release and the mentioned june release? Do you have a compare view, which you could share with me?

This is the diff view between the two release commits (June and September), but it's very long because the files have been renamed, and the watch app has changed significantly. Funnily enough the garmin addon hasn't changed that much. So if you want a sense of what's changed I think you'd be better off just checking the commit history and clicking on the individual commits to see what's changed.

[aaronjwood]

I did some more testing tonight and while I haven't found the issue yet I did notice that the memory usage of the watch app did not seem to continuously grow.

I'm wondering if there's an issue when managing the state of the connection between the watch and the phone and at some point it breaks after n hours, causing the Android service that gets launched as part of sleep tracking to stop/crash.

I have no data to back this up yet. I need to get both the watch app and the Android app hooked up to their respective debuggers. I almost have it setup but I'm running into some issues with the Android service not being able to send messages to the watch due to a FAILURE_UNKNOWN status.

[aaronjwood]

https://github.com/urbandroid-team/Sleep-as-Android-Garmin-Addon/blob/master/SleepGarmin-android/app/src/main/java/com/urbandroid/sleep/garmin/SleepAsAndroidProviderService.java#L171 doesn't seem to work correctly when running this locally with a debugger hooked up to the watch app also running locally using the ADB TCP socket. I've had to make a lot of hacks to get all of this stuff working with debuggers.

https://github.com/urbandroid-team/Sleep-as-Android-Garmin-Addon/blob/master/SleepGarmin-android/app/src/main/java/com/urbandroid/sleep/garmin/SleepAsGarminReceiver.java#L81-L82 didn't work either and I don't have enough context to know what this extra app id stuff is.

[Artaud]

...with the june release of the addon, sleep tracking works through the night for me (Vivoactive 3) and only freezes when stopping in the morning.

This is very interesting and we should definitely explore this more. I'll go through the diff and report back.

I did some more testing tonight and while I haven't found the issue yet I did notice that the memory usage of the watch app did not seem to continuously grow.

I have made the same observation while testing the app on the simulator for several hours with various devices.

I'm wondering if there's an issue when managing the state of the connection between the watch and the phone and at some point it breaks after n hours, causing the Android service that gets launched as part of sleep tracking to stop/crash.

I don't know. The main symptom is that the app on the watch stops. Even if the Android service would crash, that wouldn't cause the watch app to exit.

https://github.com/urbandroid-team/Sleep-as-Android-Garmin-Addon/blob/master/SleepGarmin-android/app/src/main/java/com/urbandroid/sleep/garmin/SleepAsAndroidProviderService.java#L171 doesn't seem to work correctly when running this locally with a debugger hooked up to the watch app also running locally using the ADB TCP socket. I've had to make a lot of hacks to get all of this stuff working with debuggers.

To use the ADB TCP socket, please switch the debug flag here. This will make sure that the correct ConnectIQ instance which uses TCP will be initialized on this line.

https://github.com/urbandroid-team/Sleep-as-Android-Garmin-Addon/blob/master/SleepGarmin-android/app/src/main/java/com/urbandroid/sleep/garmin/SleepAsGarminReceiver.java#L81-L82 didn't work either and I don't have enough context to know what this extra app id stuff is.

This is a hack that we use to be able to start the Android service from watch. The ConnectIQ SDK doesn't support starting any Android process from the watch. We found however than whenever you send any message from any watch app, the Garmin Connect Mobile app sends a INCOMING_MESSAGE broadcast, so we listen to that. The intent carries an EXTRA_APPLICATION_ID extra by which we filter out messages irrelevant to us.
But you shouldn't care about this condition at all when connecting via ADB to the simulator.

I almost have it setup but I'm running into some issues with the Android service not being able to send messages to the watch due to a FAILURE_UNKNOWN status.

This often happened to me as well in earlier releases and we found out that it was due to a bug in the watch's firmware (confirmed by Garmin) and I thought it was fixed since I didn't see it since. So what you see may either be remnants of that bug or maybe legitimate failures due to disconnection issues?

[Artaud]

Just a question, do the crashes for y'all occur if you start tracking from the phone? I just got a report that for one user it only happens when he starts from the watch.

[MrFly]

For me it crashes always ( but in a different way), regardless how it was started

[Artaud]

So I'm digging through the diff in the Android addon between today and june version.

• GlobalInitializer.java: Appears no significant change. Switching from ErrorReporter which had code copied inside the package to the same ErrorReporter in an included library. Also added debug flag.

• MainActivity.java: has changed a little but the activity itself should be irrelevant to sleep tracking

• SleepAsAndroidProviderService.java:
  This is where most of the logic resides. The changes are multiple, I list my suspects:

  • rewrote all intent communication to explicit intents through the sendExplicitBroadcastToSleep method.
  • checkAppIsAvailable() stopping the service when the watch app is not installed. Could it happen that the watch reports wrongly that the watch app is not installed, and we stop our service as a result?
  • onOpenApplicationResponse on receiving the "CHECK_CONNECTED" message. This should however have no effect since Sleep doesn't care when we send start tracking msg again and again.
  • sendNextMessage() has changed, being torn into two methods.

• SleepAsGarminReceiver.java: Can't see anything relevant...

[MrFly]

What I mentioned in my last watch report: Sometimes I'm not able to start from the phone. Could be related to checkAppIsAvailable (?), maybe... So it sounds like this could be a cause...

[aaronjwood]

...with the june release of the addon, sleep tracking works through the night for me (Vivoactive 3) and only freezes when stopping in the morning.

This is very interesting and we should definitely explore this more. I'll go through the diff and report back.

I did some more testing tonight and while I haven't found the issue yet I did notice that the memory usage of the watch app did not seem to continuously grow.

I have made the same observation while testing the app on the simulator for several hours with various devices.

I'm wondering if there's an issue when managing the state of the connection between the watch and the phone and at some point it breaks after n hours, causing the Android service that gets launched as part of sleep tracking to stop/crash.

I don't know. The main symptom is that the app on the watch stops. Even if the Android service would crash, that wouldn't cause the watch app to exit.

https://github.com/urbandroid-team/Sleep-as-Android-Garmin-Addon/blob/master/SleepGarmin-android/app/src/main/java/com/urbandroid/sleep/garmin/SleepAsAndroidProviderService.java#L171 doesn't seem to work correctly when running this locally with a debugger hooked up to the watch app also running locally using the ADB TCP socket. I've had to make a lot of hacks to get all of this stuff working with debuggers.

To use the ADB TCP socket, please switch the debug flag here. This will make sure that the correct ConnectIQ instance which uses TCP will be initialized on this line.

I had done that and got the simulator + the Android side up and running but that call doesn't return any of the devices. I actually had to change it to getKnownDevices() to get my testing to work.

https://github.com/urbandroid-team/Sleep-as-Android-Garmin-Addon/blob/master/SleepGarmin-android/app/src/main/java/com/urbandroid/sleep/garmin/SleepAsGarminReceiver.java#L81-L82 didn't work either and I don't have enough context to know what this extra app id stuff is.

This is a hack that we use to be able to start the Android service from watch. The ConnectIQ SDK doesn't support starting any Android process from the watch. We found however than whenever you send any message from any watch app, the Garmin Connect Mobile app sends a INCOMING_MESSAGE broadcast, so we listen to that. The intent carries an EXTRA_APPLICATION_ID extra by which we filter out messages irrelevant to us.
But you shouldn't care about this condition at all when connecting via ADB to the simulator.

I saw that there was no EXTRA_APPLICATION_ID being sent along so I had to comment out those two lines and just keep the conditional to ConnectIQ.INCOMING_MESSAGE.equals(intent.getAction())

I almost have it setup but I'm running into some issues with the Android service not being able to send messages to the watch due to a FAILURE_UNKNOWN status.

This often happened to me as well in earlier releases and we found out that it was due to a bug in the watch's firmware (confirmed by Garmin) and I thought it was fixed since I didn't see it since. So what you see may either be remnants of that bug or maybe legitimate failures due to disconnection issues?

Bummer, I'm not sure then. I'm not able to get any messages across from my phone to the watch. It all fails with FAILURE_UNKNOWN. All communication from the watch to the phone works okay.

[Artaud]

Sorry for not reacting faster, I was home with a sick wife and kid, I'll give it all proper attention from Monday on.

Just a note I have to drop here - one user alerted me to possibility that it might have something to do with incoming notifications. So that's a thing to test.
Seems interesting since it would explain the differences between observations and also that I never experienced the crash, since on my testing HW I'd never get a notification...

[MrFly]

Which kind of notification do you mean? My phone is always in flight mode, so no (new) notifications can come in.

[Artaud]

Okay so that probably rules it out... :/

[MrFly]

Tonight it worked.

Don't ask me, why, but it worked. I'll try to write down, what I did before starting Sleep (nothing special, it was a kind of "don't know what I'm doin' and stupid clicking around" :-D

• Enabled flight mode for going to bed
• Forgot to look on my account - so I disabled flight mode
• did anything with other apps
• Opened Garmin Addon
• Opened Garmin connect
• Synchronized the watch
• Enabled flight mode
• Started Sleep from phone - nothing happend
• (can't remember, if I disabled and enabled flight mode again, think I did, don't know why)
• Tried again, nothing happend
• Started sleep from watch
• Got IQ-Logo (crash)
• Exited Sleep (crash logo)
• Tried again
• Sleep started on the watch and phone
• Disabled the flight mode and turned the screen off

This is kind of what I'm doing every day before I got to bed except disabling the flight mode. Normally I enable the flight mode before starting any Sleep app. I can't see or imagine, why it worked today, but maybe this list will help you to find anything...

[skros89]

@MrFly Sometimes it works for me as well, there is this (seeming) randomness that I find difficult to pin down. Most of the time (not always) it works for me the first time after a fresh install of everything, and consistently crashes the second time and onwards.

@Artaud It does appear to me that something happens with the communication as sleep tracking is running for a longer time. I never have problems starting tracking (from watch or app) and if I stop tracking within a few minutes, it always works as expected. But when tracking works through the night and I stop tracking in the morning, either I get the "CIQ!" watch app crash or the watch freezes.

[MrFly]

@skros89 It never really worked for me. Since the heartrate is enabled again, I never got it running the whole night, but I can't imagine why.

Because the massive logging on the watch is not possible, could it be a possibility to log it to Android by sending it via the message queue? (kind of cheap "syslog" via Android). Just a thought of me to (maybe) have a better sight what is happening...

[ronnyadsetts]

Just to add my experience, when the Garmin watch app weas updated to re-enable heart rate, I had tracking 90% working with the previous version of the Garmon Sleep as Android add-on Android app. It's not worked, no (or minimal) tracking, since that was updated at the end of September. Sometimes the Garmin watch app is still running in the morning, sometimes not. If it is running, it can't be stopped.

[Artaud]

Guys, thanks for further input. I did a few tests during the last week and for once, I was able to reproduce the error you are seeing. It was only once and it was with the version of the app that is currently on the store. I don't have watch logs from it unfortunately but there was nothing in the phone logs.

Let me send you my attempts to fix the issue - both the watch app and the phone addon, if you would be so nice to test it for a few nights. The watch app has logging enabled and a few logs have been removed and added to make it possible to pinpoint the place where the app crashes.

You'll need to uninstall the previous Sleep Garmin as this one is built with a different certificate than the Play Store one (or your own built one).
garmin-release.zip

• Make sure to also add sleep.txt to your /GARMIN/APPS/LOGS
• Make sure to delete the previous Sleep from your watch prior to installing this.
  sleep.zip

Sorry for attaching ZIP files, Github doesn't allow apks or prgs.

[MrFly]

Ok, installed it. Will give it a try this night :-)

Btw it freezed on the watch, if I tested sensors with the both new apps and stopped the tracking from the phone.

[Artaud]

Sorry I didn't really test the test sensors. Going to my todo :blushing:

…

On Mon, Nov 19, 2018, 19:41 Hans ***@***.*** wrote: Ok, installed it. Will give it a try this night :-) Btw it freezed on the watch, if I tested sensors with the both new apps and stopped the tracking from the phone. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#10 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ADuCVieFUBdHiOhQS5lzG_GdnaGx3jC0ks5uwvtVgaJpZM4XL9tW> .

[MrFly]

lol, it's ok :-D I'll give it a try and hope to get some good logs :-)

[MrFly]

Got some logs for you, @Artaud

Sleep on the watch stopped today with the CQ-Logo. Logfiles attached, renamed the sleep.bak just for upload. There was an entry in the CIQ_LOG, too:

Edit: Oh, btw, the tracking worked the whole time; looks like it just crashed at alarm time. At least the graph goes till 4:19/20, when the SaA vibrated (phone).

---
Error: Invalid Resource Specified
Details: 'Failed invoking <symbol>'
Time: 2018-11-20T03:18:03Z
Part-Number: 006-B2700-00
Firmware-Version: '5.50'
Language-Code: deu
ConnectIQ-Version: 3.0.4
Filename: SLEEP
Appname: Sleep
Stack:
  - pc: 0x3000324c
  - pc: 0x3000305c
  - pc: 0x10000a94
    File: '/home/artaud/prog/urbandroid/source/SleepGarmin/SleepGarmin-watch/source/SleepAlarmView.mc'
    Line: 16
    Function: initialize
  - pc: 0x100018fb
    File: '/home/artaud/prog/urbandroid/source/SleepGarmin/SleepGarmin-watch/source/SleepApp.mc'
    Line: 260
    Function: timerCallback

SLEEP.TXT

SLEEP_BAK.txt

[Artaud]

This seems like a bug with the compilation process as it only happens when I compile the app for different devices one by one, but doesn't happen when I compile the whole iq package for the store and get the .prg files from that package.
Would you be willing to test one more night with the version you currently have? As most of you have experienced, the crash usually doesn't manifest itself the day of a fresh install, but a few days later.

[Artaud]

To clarify, the Invalid Resource Specified bug is that the app can't find the alarm image. It should be there but probably got lost during compilation :)

[MrFly]

@Artaud sure, I will test every night :-D No problem, I'll start it every evening, till we find something helpful.

[Artaud]

Thank you, you're a godsend :]

[MrFly]

Yes, I know :-D No problem :-)

[MrFly]

Tried again. Same error in CIQ_LOG about the resource:

Error: Invalid Resource Specified
Details: 'Failed invoking <symbol>'
Time: 2018-11-21T03:15:15Z
Part-Number: 006-B2700-00
Firmware-Version: '5.50'
Language-Code: deu
ConnectIQ-Version: 3.0.4
Filename: SLEEP
Appname: Sleep
Stack:
  - pc: 0x3000324c
  - pc: 0x3000305c
  - pc: 0x10000a94
    File: '/home/artaud/prog/urbandroid/source/SleepGarmin/SleepGarmin-watch/source/SleepAlarmView.mc'
    Line: 16
    Function: initialize
  - pc: 0x100018fb
    File: '/home/artaud/prog/urbandroid/source/SleepGarmin/SleepGarmin-watch/source/SleepApp.mc'
    Line: 260
    Function: timerCallback

This both seems to be the same than yesterday and nothing was written (if I'm right). It did not crash in the night, but it didn't vibrate to wake me up.

SLEEP2.TXT
SLEEP_BAK2.txt

[MrFly]

@Artaud love it! So much :-)

This is the log, maybe it will help you fixing the the mentioned freeze:

SLEEP.TXT

[aaronjwood]

Sleep tracking stopped/crashed almost immediately after I fell asleep last night with the new version you published :(

[MrFly]

@aaronjwood this is meanwhile an old version. A newer, and really better, version was already released. Love this one. Freezes on stop tracking and first start ends up in IQ logo, but everything else seems to work perfect now.

[aaronjwood]

Is it? I installed the version dated for 11/28 yesterday afternoon. Is there some unreleased version that you're working with?

[MrFly]

No, it's this one. For me it' working really good.