Template Tile null pointer exception on non-null parameter renderedTemplate

[kevinross]

Home Assistant Android version:
Phone: beta-2510-f9ceeb0b-full
Wearable: beta-2510-f9ceeb0b-full

Android version:
11

Phone model:
OP7

Home Assistant version:
2022.7.6

Last working Home Assistant release (if known):

Description of problem:

Reproduction of #2157 by a different user (myself). Crashed half a second after the final } was appended to the text:

{{ states.laundry_remaining.state }}

I can reproduce the crash every time so long as I clear the app data on the wearable first (the phone's app data remains, only the watch's data is cleared).

Traceback (if applicable, to get the logs you may refer to: https://companion.home-assistant.io/docs/troubleshooting/faqs/#android-crash-logs):

07-26 10:38:27.701 22816 22816 E AndroidRuntime: FATAL EXCEPTION: main
07-26 10:38:27.701 22816 22816 E AndroidRuntime: Process: io.homeassistant.companion.android, PID: 22816
07-26 10:38:27.701 22816 22816 E AndroidRuntime: java.lang.NullPointerException: Parameter specified as non-null is null: method kotlin.jvm.internal.Intrinsics.checkNotNullParameter, parameter renderedTemplate
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at io.homeassistant.companion.android.settings.wear.views.SettingsWearTemplateTileKt.SettingsWearTemplateTile(Unknown Source:19)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at io.homeassistant.companion.android.settings.wear.views.SettingsWearHomeViewKt$LoadSettingsHomeView$1$1$3.invoke(SettingsWearHomeView.kt:51)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at io.homeassistant.companion.android.settings.wear.views.SettingsWearHomeViewKt$LoadSettingsHomeView$1$1$3.invoke(SettingsWearHomeView.kt:50)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.internal.ComposableLambdaImpl.invoke(ComposableLambda.jvm.kt:116)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.internal.ComposableLambdaImpl$invoke$1.invoke(ComposableLambda.jvm.kt:127)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.internal.ComposableLambdaImpl$invoke$1.invoke(ComposableLambda.jvm.kt:127)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.RecomposeScopeImpl.compose(RecomposeScopeImpl.kt:142)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.ComposerImpl.recomposeToGroupEnd(Composer.kt:2351)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.ComposerImpl.skipCurrentGroup(Composer.kt:2611)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.ComposerImpl$doCompose$2$5.invoke(Composer.kt:3198)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.ComposerImpl$doCompose$2$5.invoke(Composer.kt:3176)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.SnapshotStateKt__DerivedStateKt.observeDerivedStateRecalculations(DerivedState.kt:252)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.SnapshotStateKt.observeDerivedStateRecalculations(Unknown Source:1)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.ComposerImpl.doCompose(Composer.kt:3176)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.ComposerImpl.recompose$runtime_release(Composer.kt:3141)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.CompositionImpl.recompose(Composition.kt:727)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.Recomposer.performRecompose(Recomposer.kt:876)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.Recomposer.access$performRecompose(Recomposer.kt:107)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.Recomposer$runRecomposeAndApplyChanges$2$2.invoke(Recomposer.kt:485)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.runtime.Recomposer$runRecomposeAndApplyChanges$2$2.invoke(Recomposer.kt:454)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.ui.platform.AndroidUiFrameClock$withFrameNanos$2$callback$1.doFrame(AndroidUiFrameClock.android.kt:34)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.ui.platform.AndroidUiDispatcher.performFrameDispatch(AndroidUiDispatcher.android.kt:109)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.ui.platform.AndroidUiDispatcher.access$performFrameDispatch(AndroidUiDispatcher.android.kt:41)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at androidx.compose.ui.platform.AndroidUiDispatcher$dispatchCallback$1.doFrame(AndroidUiDispatcher.android.kt:69)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at android.view.Choreographer$CallbackRecord.run(Choreographer.java:1350)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at android.view.Choreographer.doCallbacks(Choreographer.java:1149)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at android.view.Choreographer.doFrame(Choreographer.java:1040)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at android.view.Choreographer$FrameDisplayEventReceiver.run(Choreographer.java:1333)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at android.os.Handler.handleCallback(Handler.java:938)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at android.os.Handler.dispatchMessage(Handler.java:99)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at android.os.Looper.loop(Looper.java:233)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at android.app.ActivityThread.main(ActivityThread.java:8010)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at java.lang.reflect.Method.invoke(Native Method)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:631)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:978)
07-26 10:38:27.701 22816 22816 E AndroidRuntime:        Suppressed: kotlinx.coroutines.DiagnosticCoroutineContextException: [androidx.compose.runtime.PausableMonotonicFrameClock@9123054, androidx.compose.ui.platform.MotionDurationScaleImpl@c705bfd, StandaloneCoroutine{Cancelling}@a8c70f2, AndroidUiDispatcher@5620343]

Screenshot of problem:

Additional information:

Advised to open what amounts to a duplicate as the prior ticket was old.

[dshokouhi]

So just that we are understanding htis correctly. You clear data on the watch and don't login and continue to use the phone app to edit the template?

[kevinross]

Sorry, should've clarified there: clear data on watch, login again on the watch (the phone is never logged out or reset here, only the watch), and then, as a separate step, attempt to set the template tile content to what I quoted.

Rephrased: I start from an entirely clean config on the watch, then login, then try to set the tile content. Throughout, the phone side remains as-is (no reset, no logout-login cycle, etc); additionally, the phone app stops crashing after I clear the watch's app data and re-login the watch again (suggesting that data retrieved from the watch is breaking the phone side).

[kevinross]

Possible cause:

Here, line 53, there's a renderedTemplate param passed to the (uhhh, not terribly familiar with compose+kotlin, so terminology will probably be incorrect) view class SettingsWearTemplateTile, where from what I do know about Kotlin vis-a-vis nullable or not and specifying that in the type with a ? (or, more relevantly, the lack of)... Objects.requireNonNull() would be one option to ensure that semantics are enforced. I jumped over to the wear app's code and PhoneSettingsListener doesn't send a value for that param. I saw a recent release note re: rendering html in the template, seems likely to be the source.

[jpelgrom]

I saw a recent release note re: rendering html in the template, seems likely to be the source

That would probably refer to #2653, which hasn't been released yet.

While reviewing that PR it actually became obvious that templates can be null and it includes changes that should handle them, would you be able to install the test APKs on your phone and watch to see if the crash still happens? If not, no problem, we could wait until the changes are included in a beta release.

[kevinross]

Can I claim s/release notes/list of pull request/g? (I joke 😉)

Absolutely! I'll install them a little later this morning and let you know.

[kevinross]

Well, the phone app isn't crashing anymore, which is good, although I'm not sure it's actually sending back the rendered template from the watch: the preview is blank, or indicates a generic template error, when using a known-good previous iteration of that laundry_remaining sensor (previous iteration split the minutes and seconds up). I grabbed this from the phone-side logs (using the current iteration of the template; I can add logs for the previous iteration, but it'll take some time since I'll have to opt-out of beta, reinstall, etc first, so lmk if you'd like me to try):

: Content-Length: 113
07-28 22:05:43.104   725 13126 I okhttp.OkHttpClient: {"type":"render_template","data":{"template":{"template":"{{ states.laundry_remaining.state }}","variables":{}}}}
07-28 22:05:43.104   725 13126 I okhttp.OkHttpClient: --> END POST (113-byte body)
07-28 22:05:43.143   725   725 D SettingsWearViewModel: Successfully sent tile template to wear
07-28 22:05:43.152   725   725 D SettingsWearViewModel: onDataChanged 1
07-28 22:05:43.263   725 13126 I okhttp.OkHttpClient: <-- 200 https://instance.hostname.com (158ms)
07-28 22:05:43.263   725 13126 I okhttp.OkHttpClient: date: Fri, 29 Jul 2022 02:05:41 GMT
07-28 22:05:43.263   725 13126 I okhttp.OkHttpClient: content-type: application/json; charset=utf-8
07-28 22:05:43.264   725 13126 I okhttp.OkHttpClient: content-length: 18
07-28 22:05:43.264   725 13126 I okhttp.OkHttpClient: server: nginx/1.21.6
07-28 22:05:43.264   725 13126 I okhttp.OkHttpClient: x-powered-by: Express
07-28 22:05:43.264   725 13126 I okhttp.OkHttpClient: etag: etag-value"
07-28 22:05:43.264   725 13126 I okhttp.OkHttpClient: {"template": null}
07-28 22:05:43.265   725 13126 I okhttp.OkHttpClient: <-- END HTTP (18-byte body)

Edit: also, when the template is short enough (eg {{ states }} is sufficient to trigger this behaviour), the entire string's font colour changes to blue, and after adding 2-3 more chars, it switched to white. This is technically a separate bug, in that it's a different problem, but it's likely related to including HTML in the string, so related to this issue.

[jpelgrom]

although I'm not sure it's actually sending back the rendered template from the watch

The rendered template isn't sent between the phone and watch, only the 'original' template is sent. They render the template independently for respectively the preview in settings and the template tile.

If the preview on your phone changes, it should also send the template to the watch. Look in the logs for one of these messages, that should indicate if it is sent successfully or not:

android/app/src/full/java/io/homeassistant/companion/android/settings/wear/SettingsWearViewModel.kt

Lines 200 to 201 in 90a9a27

	addOnSuccessListener { Log.d(TAG, "Successfully sent tile template to wear") }
	addOnFailureListener { e -> Log.e(TAG, "Failed to send tile template to wear", e) }

I grabbed this from the phone-side logs (using the current iteration of the template

These logs indicate that the server result for the template {{ states.laundry_remaining.state }} is null. You can verify the result in the developer tools > template tab, but it looks like it is working as intended now? The app presents null as "Error in template".

Edit: also, when the template is short enough (eg {{ states }} is sufficient to trigger this behaviour), the entire string's font colour changes to blue, and after adding 2-3 more chars, it switched to white. This is technically a separate bug, in that it's a different problem, but it's likely related to including HTML in the string, so related to this issue.

I see the text input color randomly changing to blue, but not the white text. If you're able to reproduce it reliably, could you open a new issue for this with screenshots? The input text isn't being converted from HTML.

This issue only concerns to a NullPointerException when editing a template, inputs not rendering correctly isn't the same so to keep the discussion easier to follow another issue is preferred.

[kevinross]

rendered template not sent back

Ack

If the preview changes, check the logs

A previous comment of mine in this thread mentions exactly that log text 😄

Result of template is null

Ack

(Sidebar on app behaviour:)

App presents null as "Error in template"

IMO, that message is not correct given the template is syntactically valid and doesn't throw an exception: null is a perfectly valid, if not intended, result here. If I didn't know this now, I'd have been going over the template for syntax errors and ripping my hair out wondering why I couldn't find any; null would tell me that it's working, just not giving me the info I want. That said, this could've already been hashed out elsewhere and decided on already so I end my comments on it here.

Edit: colour of text changes at random

Not inconsistent with what I observed since I didn't spend much time on it at the time, because it'd need a new issue anyways 😄

[jpelgrom]

App presents null as "Error in template"

IMO, that message is not correct given the template is syntactically valid and doesn't throw an exception: null is a perfectly valid, if not intended, result here. If I didn't know this now, I'd have been going over the template for syntax errors and ripping my hair out wondering why I couldn't find any; null would tell me that it's working, just not giving me the info I want. That said, this could've already been hashed out elsewhere and decided on already so I end my comments on it here.

This wasn't discussed in depth so your comment is welcome 🙂. I agree and have submitted a change to improve it; null will show up as "null" like in the developer tools instead of suggesting there is an error.

[jpelgrom]

The change I referred to has been merged and with that I believe the original crash and related problems have been solved. Closing this issue as completed.

If you're able to reliably reproduce the color of the preview changing when editing a template on the latest beta release of the app (beta-2556 or newer), feel free to open a new issue. As I previously said, I don't believe it is related to the HTML or template itself and haven't observed exactly the same.