So, I went for a quick 3km run on a treadmill. After that I synced my MiBand with GadgetBridge, and this was the result: https://jii.moe/4y_qKKmo.jpg
As you can see, the step count got negative. This is making pretty hard to reach my 10000 step goal :)
This is the gadgetbridge.log file: https://jii.moe/EkvtttQj.log
I didn't have logging enabled during the first sync, but I enabled it right away. A successive sync increased the number or negative steps, so hopefully something useful got caught in the logs.
Also I enabled logging previously, so probably most of the stuff at the beginning is not related at all. I guess putting a date in the log might be useful? ;)
I don't know if it helps, but currently the MiBand is recognizing me as sleeping (or at least the graph says so): https://jii.moe/NJk09KQo.jpg (as for my weird schedule, I'm working on shift).
GadgetBridge version: 0.4.5
MiBand Firmware: 220.127.116.11
Android Version: 5.1.1 (CyanogenMod 12.1)
Thanks for the great app, it's awesome to be able to use the MiBand using only free software!
I forgot to add that this isn't the first time I noticed the step counter going backward. Also,
I noticed once or twice that the number of steps was not in sync with the number on the MiBand (to make this clear: the MiBand vibrated to signal that I had reach my goal, I synced after two minutes and GadgetBridge was reporting about 9000 steps out of 10000).
Thanks for the detailed report and sorry for your making your goal unreachable... We'll fix this for the next version!
As Carsten said, sorry for the bug. Right now there are two hypothesis, and both are possible according to the logs you sent. Is it possible for you to share the gadgetbridge database with us? You can export it from the debug screen (activity, in Android terms :) using the "export db" button. Idf you don't see the button, than it may be that you need to update to a newer version of gadgetbridge.
As for the wrong sleeping time, I have experienced that some firmwares for the band are much more time-oriented than others, in the sense that the band will start classifying activities as sleep at determined hours. It may be that 18.104.22.168 is using this time based heuristic... If you find other firmwares you can try installing another one. In the wiki I tried to summarize the one I tested (to some extent).
Hi, thanks for the replies guys.
This is my database: https://jii.moe/4158Tt4s
As for the sleep times, I know it's not Gadgetbridge fault, don't worry.
In my experience, the best firmware was the one shipped with the 1.3.312 release (according to the Internet, firmware 22.214.171.124), but I'm not so keen on upgrading my band after losing one to a firmware update.
Or maybe I'll update to version 126.96.36.199, given that according to your tests it seems the best one.
I can just go ahead and flash using Gadgetbridge, or that's not stable/tested enough yet?
Thanks! I just downloaded the database, if you prefer to delete it from your server please do so.
One of the possible causes for your negative steps count is a bt transfer problem. If this is the case, uploading a firmware may result in a corrupted transfer and a broken miband. After we exclude this cause you can try to upgrade or downgrade with gadgetbridge: I did so many times and my band is still alive (fingers crossed) :)
Excellent, thanks for your testing! I'll close this issue for now, hoping it is indeed fixed. If it isn't, please reopen it.
Sorry if it took so long to reply, I've been on a small vacation. I've tested it again on a treadmill, and I can confirm that I see no negative steps. So I guess this is really fixed for good.
Thank guys :)
@danielegobbetti Thanks for the information. I'm happy with what it's working so far, but maybe I'll update in the future.
I just upgraded to the 0.5.2 release, and right after that I've seen a decrease of steps when I synced :/ It went from about 7500 steps to about 7000, and then from 7000 to about 6900.
This is the log: https://jii.moe/V1CGEP0h.log
Does the tiny black text in the other activity charts show the correct date and time? After synchronizing it should show data to about the current hour and minute.
I think I've found the bug... just need to fix Android Studio so that I can actually test the fix. The good news is that your data in the db is probably correct :-)
Thinking about it some more, there should be another bug.
The problem with the wrong date was only introduced yesterday, so it's not in 0.5.2.
And in any case, even if the day is wrong, the value should not decrease multiple times.
FYI, I add some checks for negative values, so with current HEAD, you shouldn't see decreasing values anymore. Such negative values are now logged instead, so the next log would show us whether this happens indeed.
While we are investigating the issue I would suggest that you don't sync data. It may be that they get corrupted and we don't know if that is recoverable (this happened to me also with current master).
The data already in the dB are safe and the miband is able to hold at least 20 days of data without syncing.
@Spittie Do you have a reliable way to trigger this? I haven't ever experienced this, but then I don't run on a treadmill. We're about to release a new version this weekend, so when it happens again, the corresponding log should help identify the cause.
Sorry for the late reply guys, been somewhat busy.
I had a reliable way to trigger this, which was running on a treadmill, but
a66a3a15c2 fixed that for me.
The behavior I've described in https://github.com/Freeyourgadget/Gadgetbridge/issues/91#issuecomment-136655928 just happened once and I haven't seen it happens again yet.
It actually happened right after I upgraded from 0.5.1 to 0.5.2, and I didn't disconnect/reconnect my band after the upgrade, so maybe this could have been the problem? It got fixed by quitting Gadgetbridge.
Anyway I've updated to the new version, I'll let you know if I happen to see this again. In the meanwhile I guess you can close the ticket?
Alright, thanks for the feedback. I'll close the issue for now and will have a look at what happens when upgrading Gadgetbridge versions without restarting the app. No idea if Android might re-load classes from the new version when starting a new activity.
Seems that I experience something like that every time this ticket gets closed :/
This time I just synced, and it dropped my steps from ~6500 to ~1500. I can't see anything particular from the logs: https://jii.moe/NJdrFHYa.log
Thanks again for your thorough report. Before having a look at all this -- did you really use gadgetbridge 0.4.5 or was that a typo?
Uh? I was using GadgetBridge 0.4.5 when I opened this ticket, but now I'm (obviously?) running the latest stable, 0.5.3 :)
D'oh! I expected the android github client to show the newest contents on top, so I actually looked at your very first submission. Thanks :-)
To get this right:
- you synced a few times today and gb showed 6500 steps for today
- then you synced another time and suddenly gb showed just 1500 steps?
And you didn't change the day in the charts activity, so it always displayed the data of today?
I again added some logging and barriers against negative values, so even if we don't add negative values ourselves (there's nothing in your logs), we willl now fail hard when we get negative values from the database.
I have these possible explanations:
- the day is wrong and you see data of the wrong day (either before syncing or afterwards)
- the database returns completely wrong values, for whatever reasons (rather unlikely)
- the database query returns too few values, for whatever reason (we will catch this in the next log)
- we somehow overwrite existing sample entries in the db with wrong entries (with fewer steps), maybe because the time of the band is way off.
Scrap all this. It's most probably the time. See the log for TIMESTAMP:
FetchActivityOperation - TIMESTAMP: 8 Sep 2015 23:45:05
FetchActivityOperation - TIMESTAMP: 9 Sep 2015 06:10:46
FetchActivityOperation - TIMESTAMP: 9 Sep 2015 10:35:46
FetchActivityOperation - TIMESTAMP: 22 Jan 2000 00:00:43 <-- EEK
FetchActivityOperation - TIMESTAMP: 9 Sep 2015 12:12:46
FetchActivityOperation - TIMESTAMP: 9 Sep 2015 16:04:46
FetchActivityOperation - TIMESTAMP: 9 Sep 2015 17:59:46
Now I need to find out what to do with this. Could you export and save your DB for an analysis?
Yeah, that's the one Gadgetbridge created when I pressed "export database". I've done it again and this time is almost two times as big, so I guess it's the completed one? Here you go: https://jii.moe/EyBPo2o6
Looked at the wrong day previously, but now I found something:
select timestamp,steps from GBActivitySamples s where s.timestamp > 1441787000 and s.timestamp < 1441796300 order by timestamp;
There's indeed data missing, and exactly the data which contained the bad timestamp (22 Jan 2000 00:00:43).
The data "hole" is explainable now, but now I'm still wondering where, the 4000 steps are lost. AFAICS from the database and the log, those missing samples have never been there. So where did you see the 6500? When was that value shown (after which sync)?
Okay, I'm checking the log and thinking I'm going crazy :)
I do (or at least I think) remember syncing the band at least once between 10:37 and 12:13, and that would be when I saw the ~6500 steps.
But there is no trace of that in the logs :/
I don't really know what to say, sorry guys.
On a more happy tone, @danielegobbetti I updated the firmware of the band and no hamster was eaten :)
Well, so let's close the issue again and wait for it to happen again ;-)
FWIW, there is a live-activity-data branch which has another chart, supposed to show live steps. It's really very much WIP, but you might use it to validate your step count. IIRC, the accumulated step count in that chart starts at zero, so that you know how many steps you did on the treadmill.
Like a clock :) This time seems a bit different, but oh well.
This time I can be a bit more precise.
- I synced my band this morning at ~8:30, and saw about ~6000 steps. This was likely the correct count.
- Then I didn't sync my band for most of the day, and synced it again at about ~18:30 (which is in the logs this time, at 18:26). Gadgetbridge showed ~14500 steps for me, which was actually wrong, as I didn't reach my 12000 step goal yet (band didn't vibrate yet. Also only two leds were firm when doing the "hand gesture" to show your current status).
- And then I synced my band at ~19:30 (19:35 from the logs), and the steps dropped down to ~12800, which is likely the correct count (the band did vibrate between 18:30 and 19:30).
From the logs, I can see this:
18:26:34.268 [Binder_1] WARN n.f.g.s.d.m.o.FetchActivityOperation - GOT UNEXPECTED ACTIVITY DATA WITH LENGTH: 15, EXPECTED LENGTH: 95 18:26:34.269 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x 0 18:26:34.269 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x3e 18:26:34.269 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x e 18:26:34.270 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x 0 18:26:34.270 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x4c 18:26:34.270 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x 0 18:26:34.271 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x52 18:26:34.272 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x 0 18:26:34.272 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x 1 18:26:34.273 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x56 18:26:34.273 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x1f 18:26:34.273 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x 1 18:26:34.274 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x64 18:26:34.276 [Binder_1] WARN n.f.g.s.d.m.MiBandSupport - DATA: 0x52
I opened the issue again @Spittie .
Unfortunately I don't have time to look at your log at the moment, but from what you tell us there are some issues with the bluetooth stack.
A discussion about making our stack more robust is in the issue https://github.com/Freeyourgadget/Gadgetbridge/issues/68.
Back to your problem, what the logcat shows is that 4 packets where lost during transfer (each packet is 20 byte long), but since each minute is 3 bytes long, the data gets mis-aligned. What this means for istance is that a value which was meant to be an "intensity", ends up being a step count.
In the end you have wrong data in the DB, but when this happens we do not confirm the transfer to the band, hence its memory is not cleared and the next time you sync the bad data gets overwritten (hopefully with correct readings).
There is little we can do to avoid the packet loss (plus it happens irregularly, and therefore it's difficult to test), but perhaps we could find a way to prevent showing the user wrong data.
(@cpfeiffer could we use a transaction for writing the data to the db, and roll it back in case of problems? )
Do you have an idea whether also in the past (except the very first issue of running on the treadmill) the likely number of steps was the smaller one? In this case I'd close this issue and concentrate the effort on https://github.com/Freeyourgadget/Gadgetbridge/issues/68 because this is the actual problem.
Yeah, this one did sound like some bluetooth problem, sorry.
I don't know about the other one, but in this comment https://github.com/Freeyourgadget/Gadgetbridge/issues/91#issuecomment-138959615 I'm 99% sure that the correct step count was the bigger one. If only, because I did walk ~2km with my dog that morning.
I didn't really do anything weird today, beside updating (actually downgrading) the firmware of my band.
In the logs I can see the wrong timestamp:
:16:53.781 [Binder_B] INFO n.f.g.s.d.m.o.FetchActivityOperation - TIMESTAMP: 29 Apr 2000 09:02:57 magic byte: 18813
I don't have a lot of info's this time, sorry, as I didn't really think about it and didn't annotate the times. I only know that my band vibrated for the reached goal (12000 steps) at 18:26, I did sync GB right after and it was showing only 7166 steps.
Do you remember which version you used? On September 23rd (
d9b4bbe550), I added some code to deal with your time warp (year 2000 entries). Did you run a version with that code?
If you used an earlier version, the data with the bogus timestamp would not be honored for the current day, so these steps would be missing.
Additionally, I see some entries like this:
12:16:53.752 [Binder_B] DEBUG n.f.g.s.d.m.o.FetchActivityOperation - activity data: length: 20, remaining bytes: 491 12:16:53.752 [Binder_B] DEBUG n.f.g.s.b.BtLEQueue - characteristic changed: 0000ff07-0000-1000-8000-00805f9b34fb 12:16:53.753 [Binder_B] DEBUG n.f.g.s.b.BtLEQueue - characteristic changed: 0000ff07-0000-1000-8000-00805f9b34fb 12:16:53.754 [Binder_B] DEBUG n.f.g.s.d.m.o.FetchActivityOperation - activity data: length: 20, remaining bytes: 451
Somehow, 20 bytes are not received.
I'm fairly sure I was running 0.6.0 (I made my post on the 26th, and 0.6.1 was uploaded to F-Droid the 28th).
I can't test anymore as my band died tho :/ I'll let you guys know if I I get a new band (not so likely, this is the second one dying on me after a bunch of months) and still experience this.
Too bad :( If you ever get it to connect again (using latest version of Gadgetbridge) it should gracefully deal with those time problems. Otherwise: good luck getting a new band. In case you decide to go for a different manufacturer, we're interested in supporting more devices :)
Deleting a branch is permanent. It CANNOT be undone. Continue?