Watch face is not updated sometimes

[polarfish]

I have Samsung Galaxy Watch 4. Nightwear has been working fine on it when I was using Nightscout in tandem with https://github.com/benceszasz/xDripCareLinkFollower. Now I changed to Nightscout with https://github.com/nightscout/minimed-connect-to-nightscout (to get rid of the extra phone in the chain) and I started experiencing delays in refresh (1-2 hours) on my watch when on another watch (Apple Watch 7) it continues to work well (with different application for apple watches).

I checked that I have access to the Internet from my watch, my Nightscout is working fine - last update is 3 minutes ago on UI (and the /api/v1/entries/sgv.json call shows the same), but the watch face shows data for 70 minutes ago. Sometimes it picks up and start refreshing for an hour or two but then it "freezes" again.

I assume that something in my Nightscout setup affected the watch face operation but it still strange for me see that the site is working fine and the watch face is not.

I would be glad to gather more debug information but I need an advice (I have no experience in developing for Android Wear)

[polarfish]

I gathered some access logs through Caddy logging: The correct calls produce log like below:

"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.021431626 sec"

"Bad" calls (just a several minutes "freeze") produce logs like below:

"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 2.948966746 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 5.340778666 sec"
... (some time passes)
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 2.869126223 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 4.717089679 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 2.844151628 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 5.372384226 sec"
... (and then it's back again)
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 2.188058265 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.393125903 sec"

[polarfish]

a "good" call full log entry

{
  "level": "info",
  "ts": 1684839562.6804292,
  "logger": "http.log.access.log0",
  "msg": "handled request",
  "request": {
    "remote_ip": "REDACTED",
    "remote_port": "47026",
    "proto": "HTTP/1.1",
    "method": "GET",
    "host": "REDACTED",
    "uri": "/api/v1/entries/sgv",
    "headers": {
      "If-None-Match": [
        "W/\"2c5-+QJONi7Zgqs4MDiSs3+U7ZymKHU\""
      ],
      "If-Modified-Since": [
        "Tue, 23 May 2023 10:50:00 GMT"
      ],
      "User-Agent": [
        "Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001)"
      ],
      "Connection": [
        "Keep-Alive"
      ],
      "Accept-Encoding": [
        "gzip"
      ]
    },
    "tls": {
      "resumed": true,
      "version": 772,
      "cipher_suite": 4867,
      "proto": "http/1.1",
      "server_name": "REDACTED"
    }
  },
  "user_id": "",
  "duration": 0.019809449,
  "size": 702,
  "status": 200,
  "resp_headers": {
    "Alt-Svc": [
      "h3=\":443\"; ma=2592000"
    ],
    "Access-Control-Allow-Origin": [
      "*"
    ],
    "Etag": [
      "W/\"2be-iGCWImb9nA8mUsqHZLUYbL5ZfMQ\""
    ],
    "Access-Control-Allow-Methods": [
      "GET,PUT,POST,DELETE,OPTIONS"
    ],
    "Last-Modified": [
      "Tue, 23 May 2023 10:55:00 GMT"
    ],
    "Vary": [
      "Accept, Accept-Encoding"
    ],
    "Access-Control-Allow-Headers": [
      "Content-Type, Authorization, Content-Length, X-Requested-With"
    ],
    "Date": [
      "Tue, 23 May 2023 10:59:22 GMT"
    ],
    "Server": [
      "Caddy"
    ],
    "X-Powered-By": [
      "Express"
    ],
    "Content-Type": [
      "text/plain; charset=utf-8"
    ],
    "Content-Length": [
      "702"
    ]
  }
}

[polarfish]

a "bad" call full log entry

{
  "level": "info",
  "ts": 1684839435.9383264,
  "logger": "http.log.access.log0",
  "msg": "handled request",
  "request": {
    "remote_ip": "REDACTED",
    "remote_port": "47004",
    "proto": "HTTP/1.1",
    "method": "GET",
    "host": "REDACTED",
    "uri": "/api/v1/entries/sgv",
    "headers": {
      "If-None-Match": [
        "W/\"2c5-+QJONi7Zgqs4MDiSs3+U7ZymKHU\""
      ],
      "If-Modified-Since": [
        "Tue, 23 May 2023 10:50:00 GMT"
      ],
      "User-Agent": [
        "Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001)"
      ],
      "Connection": [
        "Keep-Alive"
      ],
      "Accept-Encoding": [
        "gzip"
      ]
    },
    "tls": {
      "resumed": true,
      "version": 772,
      "cipher_suite": 4867,
      "proto": "http/1.1",
      "server_name": "REDACTED"
    }
  },
  "user_id": "",
  "duration": 5.329110298,
  "size": 0,
  "status": 0,
  "resp_headers": {
    "Server": [
      "Caddy"
    ],
    "Alt-Svc": [
      "h3=\":443\"; ma=2592000"
    ]
  }
}

[polarfish]

I "grepped" all the calls for an hour or something and it seems to be connected with the duration.

"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.033113457 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.020635331 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 2.710480008 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 3.275049728 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.032667155 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.021028637 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.093424892 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.023691112 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.065770688 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.085795238 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.073099869 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.021156885 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.021431626 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 2.948966746 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 5.340778666 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 2.869126223 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 4.717089679 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 2.844151628 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 5.372384226 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 2.188058265 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.393125903 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 2.372462771 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 5.329110298 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.019809449 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.016969851 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.019979586 sec"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.01490545 sec"

[polarfish]

Another situation - I reloaded my watches and waited for the watchface to start showing values and it didn't show any values (it had just ___) for almost 30 minutes. This is the access log:

"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.03s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.02s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.02s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.78s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.02s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 1.39s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.02s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.02s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.06s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.02s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.06s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.07s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.02s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.03s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.98s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.05s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 304 0.02s"
... somewhere here it started showing values
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.07s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.07s"
"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 200 0.07s"

[rahim]

Hi @polarfish - sorry you're having issues. Thanks for detailed debugging info.

My partner has a Galaxy Watch 4, but typically doesn't use NightWear (she prefers to have the graph from a now defunct predecessor of XDrip). When I have tried it in the past I've not noticed similar issues, but I've only run it for short periods.

What version of the NightScout server are you using and is there anything interesting about your configuration worth knowing? Are you using authentication? (earlier NightWear versions only supported instances that were public).

When I get a chance I'll have a look on her watch to see whether I can recreate.

Things perhaps worth trying to reveal more information:

• restarting the watch
• terminating the NightWear process from settings and/or switching the Watch Face for another and then back again

These entries with "0" as reported as the response code are curious

"Dalvik/2.1.0 (Linux; U; Android 11; SM-R860 Build/RWS3.220419.001) GET /api/v1/entries/sgv 0 2.710480008 sec"

Where are you pulling these request logs from?

Depending on how much appetite you have for digging in to this, I can help you get set up with a debug build so you can remotely connect with Android Studio's logcat to surface more information.

[polarfish]

What version of the NightScout server are you using and is there anything interesting about your configuration worth knowing? Are you using authentication? (earlier NightWear versions only supported instances that were public).

NightScout 14.2.6, runs in Docker v20.10.21, behind Caddy v2.6.4, on Ubuntu 20.04.6 LTS, on a Raspberry Pi 3 Model B+ No authentication

Things perhaps worth trying to reveal more information: restarting the watch, terminating the NightWear process from settings and/or switching the Watch Face for another and then back again;

I tried changing faces - nothing (visually) changes I tried restarting my watch - in case the watch face is in the "frozen" state, I do not see anything but 3 underscores on a black screen.

These entries with "0" as reported as the response code are curious

For me as well. I found only this topic https://caddy.community/t/http-status-code-0-in-caddy-logs-for-a-reverse-proxy-with-template/18685 but doesn't really apply to my case

Where are you pulling these request logs from?

https://caddyserver.com/docs/caddyfile/directives/log

mysite.example.com {
  reverse_proxy localhost:1337
  log {
    output file /var/log/caddy/mysite.example.com-access.log {
    roll_size 10mb
    roll_keep 20
    roll_keep_for 720h
  }
}

If to put this 0 http codes aside I assume it's something with 304 responses. In this comment https://github.com/rahim/nightwear/issues/41#issuecomment-1559551597 I observed the situation when the calls from my watch are coming in pairs, so I see two logs appear at a time, one with 200, another one with 304. I assume every time the last call returned 304 - the watch face didn't update itself. I wanted to try without caching by getting rid of 304 responses on Caddy with (removing If-Modified-Since, adding Cache-Control no-cache), then I saw only 200 being returned to the watch, but unfortunately minimed-connect-to-nightscout stopped working 2 days ago because of changes on the side of Medtronic, so I cannot emulate the problematic situation anymore.

Considering that minimed-connect-to-nightscout is not working and the project is not really supported, I decided to move back to xDripCareLinkFollower (with the extra worker android phone), so this issue is not relevant to me anymore.

But still @rahim what do you think about modifying the watch face logic to always request values with no caching (removing If-Modified-Since, adding Cache-Control no-cache)?

[rahim]

Sorry for the very delayed response @polarfish , I missed your last reply.

I'll have a think about the caching suggestion - it sounds reasonable that we'd not ever want a cached response (we're doing our best to minimise our request frequency while prioritising freshness of reading available to the user. There's still something I don't understand about this particular scenario though, it doesn't seem to be one anyone else has reported. If it is to do with caching behaviour, I think that will be because caddy is layering some smarts that takes account of some of those headers where most nightscout installations aren't.

unfortunately minimed-connect-to-nightscout stopped working 2 days ago because of changes on the side of Medtronic

:(

I got bitten by this too, shame I didn't see this earlier! We use XDrip's carelink collector to bring BG readings and bolus data from the pump alongside the SG data we have from Dexcom in Nightscout.

[polarfish]

I am closing the issue because the current setup (with XDrip+ CareLink Follower) gives no problems.