phyphox / phyphox-android

Physical Phone Experiments
GNU General Public License v3.0
319 stars 42 forks source link

Light sensor time axis jumps back to earlier times #37

Closed lgommans closed 1 year ago

lgommans commented 1 year ago

Greetings from the future!

Thank you, kind person from the past, for making this wonderful application. It brings us peoples from the future much joy :)

The light experiment seemingly allows the user to time travel. While some may see this as a boon, I find the strange lines in the graph hard to interpret. Here is an example:

12th data point suddenly looping back to a time of zero seconds

After eleven data points, the application decides it has had enough of the present timeline and decides to travel several seconds backwards in time to record a history in an alternate universe.

Downloading the CSV data:

"Time (s)","Illuminance (lx)"
1.751839330E-1,1.970000000E2
4.751839330E-1,1.420000000E2
7.751839330E-1,6.500000000E1
1.075183933E0,2.600000000E1
1.385183933E0,2.150000000E2
1.713183933E0,3.510000000E2
2.053183933E0,3.320000000E2
2.554419441E0,3.430000000E2
2.896919441E0,1.560000000E2
3.239141663E0,1.410000000E2
0.000000000E0,1.020000000E2
3.418188180E-1,5.400000000E1

Another example:

image

It happens quite consistently after a handful of data points, though only once, and seemingly only with the light experiment (maybe that means the issue should be opened under https://github.com/phyphox/phyphox-experiments?). I didn't see anything unusual in the experiment definition, but I'm also not familiar with the format.

One discrepancy between the phone and the web view is that the web view will load the data identically to the phone, then reconsider, and draws a little connecting line between the most recently added data point and the next data point from the old timeline, even though data collection is currently paused.

line being added shortly after loading

The phone does not draw this extra line.

Finally, here's an exported state from phyphox in case that helps: Licht 2022-12-03 23-18-24.phyphox.notreallyzip.zip (GitHub doesn't allow uploading files with a .phyphox extension, yet..!, so I renamed the file to end in .zip).

My device is a Samsung S10e (SM-G970F), light sensor "TCS3407 Uncalibrated lux Sensor", using phyphox 1.1.11 (build 1011102). To reproduce, it seems I need to have light changes as fast as the sensor can pick up from the start. I'd estimate it's a greater than 50% hit rate and always within about 15 data points.

Expected result: if the sensor somehow outputs timestamped data and the timestamp gets messed up for some reason (but then never again?), I would like it if phyphox (perhaps optionally) does a sanity check on the timestamp and otherwise just takes the current wall clock time as the timestamp to associate with the data point. Or perhaps for consistency: always takes the wall clock time if this option is enabled.

PS. Once upon a time, I requested a wiki account, probably under the name Luc or LucGommans, but never heard back. In my inbox is only a purple link to confirm an email address on 2022-01-02. Are accounts not available to the general public?

Staacks commented 1 year ago

This might be a device specific issue as phyphox usually just adds an offset to the sensor event timestamp, so the time axis starts at 0. Luckily I will be able to try it on a Samsung Galaxy S10 5G, so if they are not too different I should be able to reproduce this when I find the time.

But I can answer the PS now: Originally our Wiki was open to anyone, but we lost the fight against spam bots. Even now with account requests and a captcha we still get more spam than anything including random scientific text excerpts in the "about me" box. Therefore, I pretty much only approve requests by names I recognize or when I was expecting a request. So, just request it again and I will approve it.

lgommans commented 1 year ago

we lost the fight against spam bots.

Darn, that's annoying. This is why we can't have nice things... Might be worth a notice on the website, though, as (imo) creating the personal info text that will be shown on your profile later is not a five second task, at least for perfectionist me it is not :-). Anyhow, I've re-requested it just now! Not sure anymore what I had planned to contribute back then, but probably I will find a use for it again sooner or later, so I figured I might as well request it now. (Email timestamp: Tue, 6 Dec 2022 00:27:46 +0100, IP address 78.x.x.x, name Luc.) Thanks!

Luckily I will be able to try it on a Samsung Galaxy S10 5G

Oh that will be interesting!

Just tried another device as well: Huawei P10 Lite which has a proper light sensor that simply gives you data instead of filtering on changes. There, the bug does not reproduce as stated; however, when pausing I got a little backwards piece on the line as well:

different light value added ~40ms back in time

It does not happen every time I pause, maybe one in three times?

Just realized I have one more device from work, Pixel 6 regular, and lo and behold... the light sensor also acts funky there! After clearing data and starting again, the timestamp starts where it left off previously (e.g. at 40 seconds). This does not happen when closing and reopening the experiment.

Pausing and resuming has the same issue as for the P10L (though this is an "update on large change" device whereas the P10L is not). The pause-resume thing, I cannot reproduce on my S10e (n=10), though after those 10 pauses/resumes with ~4 data points on average between them, it decided to happily start recording from t=0 again so my previous remark that it's always within the first few data points is wrong. Perhaps within the first few after starting or unpausing? Not sure. Curious if you can get this reproduced!

Staacks commented 1 year ago

Perfect, I could reproduce both problems (and am a bit annoyed that I did not notice the pause issue on the Pixel 6 as I use one of those as my personal device).

In fact, these seem to be three separate issues, all caused by the irregular updates of the light sensor and I can only fix two of them:

1 When phyphox subscribes to updates from the light sensor, it often receives an immediate update from an event that has happened before the experiment was started. This makes sense and is to be expected on "slow" background sensors like light or GPS as the system does not measure just because phyphox asks for data, but it is measuring continuously and just gives phyphox the current state with a timestamp of when it was measured. I simply adjust the timestamp of any "historic value" to the beginning of the measurement (t = 0), but forgot to do the same for values after the pause. Instead they fall before the pause and therefore into the previous measurement period. The fix is that now values are always adjusted to the last start instead only to t = 0. This should fix the issue on the P10L and the similar issue on the Pixel 6.


2 Some devices have a bad implementation for the timestamp of sensor events and a permanent offset. The examples I encountered are usually massive offsets due to an entirely different reference point and phyphox has some heuristic detection to notice and fix this issue (i.e. measurements that are more than 10 seconds before the start of the measurement and timestamps that are in the future). The problem is that my S10 5G actually generates timestamps that sometimes are a few milliseconds in the future. My implementation for the correction expects that this would happen already for the first measurement and also adjusts this to t = 0, but since it happens randomly on the S10 5G it suddenly jumps back to t = 0 at a random point. I will not entirely remove my correction algorithm here because generating future timestamps is definitely an error on Samsungs behalf, but I will improve it such that it does not correct to t = 0 but the current timestamp (which is more accurate for all cases anyways). So, in the next version you might notice a minor shift in timestamps at some point, but not a jump back to zero.


3 This is the one I cannot fix: During my tests the S10 5G actually generated a few sensor events out of order. A simple debug output right after the sensor callback gave me these timestamps:

2022-12-06 16:07:33.895 22330-22330/de.rwth_aachen.phyphox D/SensorInput: Event at 4557354576403, 4548465412855
2022-12-06 16:07:34.637 22330-22330/de.rwth_aachen.phyphox D/SensorInput: Event at 4558094576403, 4549207184085
2022-12-06 16:07:34.936 22330-22330/de.rwth_aachen.phyphox D/SensorInput: Event at 4558394587403, 4549506128239
2022-12-06 16:07:35.236 22330-22330/de.rwth_aachen.phyphox D/SensorInput: Event at 4549797375738, 4549806580085
2022-12-06 16:07:35.536 22330-22330/de.rwth_aachen.phyphox D/SensorInput: Event at 4550097375738, 4550106165815

The first large value after "Event at" is the timestamp of the sensor event and the second is SystemClock.elapsedRealtimeNanos(), i.e. the reference clock from the system in nanoseconds. As you can see the Samsung generates events almost 10 seconds in the future and then jumps back. Often it is not that bad and if it happens during the first measurement it will trip my offset-fix-code which will lead to a bunch of events adjusted back to zero, but the only way to fix this would be to discard the timestamp altogether and just determine the time when we receive the event. And this would be the worse option for all other phones and particularly for faster sensors.


This leaves the other issue for the Pixel 6 that deleting data leads to the Pixel to resume at the old timestamp, but unfortunately I could not reproduce it on my Pixel 6. Is it a rare thing or did I miss something that is needed to reproduce it?


About the Wiki account: I have approved it, so it should now be working for you.

lgommans commented 1 year ago

Thanks for picking this up so thoroughly!

This leaves the other issue for the Pixel 6 that deleting data leads to the Pixel to resume at the old timestamp, but unfortunately I could not reproduce it on my Pixel 6. Is it a rare thing or did I miss something that is needed to reproduce it?

Hmm, it seems I've been describing it wrong. To start from the beginning, one run might be:

  1. I've used the app before step one which, given that the sensor/OS apparently provides timestamps along with the values, might influence matters.
  2. Kill app from the system menu ("force stop", not just swiping away)
  3. Open app and open the light experiment
  4. Click "play" (start)
  5. A line appears from time=0 (with some value, e.g. 300) to time=231.5 (with some other value, e.g. 90)
  6. From here it appends data at a normal time scale, adding another data point at e.g. time=237, another at time=237.4, etc.
  7. Click pause
  8. When expanding the graph, most of it turns red now (translucent background color). I think the red color means the experiment was not running here. Only the section from time=0 until time=~15s is not red but has the original black background color. The data is still shown starting from the offset of 231.5 seconds and zooming/panning doesn't change these things.
  9. Clear data and press start again
  10. A line appears, starting with an offset of time=18.58 (no line starting at time=0 this time) and very next data point is at time=243.x. Recording data normally from there on.

When previously trying this, I think the start offsets (I tried multiple times) after clearing data were plausibly in line with values fitting my assumption that clearing data did not clear the time offset. Now that I try it again and get a much larger value, I see that my description was wrong.

Sometimes, either after killing the app or after clearing the data, it works fine and simply starts from zero. Maybe one in four times? I hadn't noticed this before as it's my work device, it's not involved in many experiments generally, and these new light sensors are annoying anyway (needing to artificially cause a large change for it to show anything at all, at which point you've borked your own data... limited usefulness unfortunately, not like the good old days *wistful* :P).

I could drop by the RWTH if you would like to debug why the app behaves differently on my device. (Complete coincidence that I live nearby btw, I first noticed it on F-Droid's new releases or so and was very happy there's finally a good, comprehensive sensors app on F-Droid.)

Staacks commented 1 year ago

Ah, thanks, I got it and can now reproduce it every time. As I mentioned, you usually get an old value from before the beginning of the measurement as this is the most recent one. If there is no change in light for more than 10 seconds before starting the measurement, this old value will be more than 10s in the past and trigger my correction algorithm.

So, to reproduce, simply keep your finger above the play button and keep still for 10 seconds in order to not cause a change in the light shining onto the device before actually pressing play.

The fix is simple: I will increase the threshold to an offset of 600s. I think the bad implementations that we try to fix are further off and it is unlikely to get such an old value. I certainly prefer to have the Pixel working properly as it reports correct timestamps instead of fixing an error in the implementation of some obscure device.

Should be fixed in next version. Feel free to reopen if something still feels off and thanks for helping to fix this issue.