webosose / sam

Systems and application manager
Apache License 2.0
8 stars 12 forks source link

Web applications that take longer than 10s to load are killed #2

Open martin-ejdestig opened 4 years ago

martin-ejdestig commented 4 years ago

Have taken https://github.com/webosose/test-apps/tree/master/com.webos.app.test.youtube and just replaced:

window.location = "http://www.youtube.com"

with

window.location = "http://svtplay.se"

And modified other strings by just replacing "Youtube" with "SVT Play". Just for testing.

On a RPI4 with webOS OSE 2.5.0 it looks like it very often takes longer than 10s for svtplay.se to load. I can see the following in the journal:

$ grep  "Changed:\|timeout\|killApp" journal-svt-does-not-start.txt 
Jul 15 09:05:01 raspberrypi4 sam[607]: [I][RunningApp][setLifeStatus][75bf8a7a-5408-453a-bb4b-4451e93b52fd0] Changed: com.luxoft.app.test.svtplay.0 (stop ==> splashing)
Jul 15 09:05:11 raspberrypi4 sam[607]: [I][RunningApp][setLifeStatus][75bf8a7a-5408-453a-bb4b-4451e93b52fd0] Changed: com.luxoft.app.test.svtplay.0 (splashing ==> splashed)
Jul 15 09:05:11 raspberrypi4 sam[607]: [I][RunningApp][setLifeStatus][75bf8a7a-5408-453a-bb4b-4451e93b52fd0] Changed: com.luxoft.app.test.svtplay.0 (splashed ==> launching)
Jul 15 09:05:11 raspberrypi4 sam[607]: [W][RunningApp][onKillingTimer][75bf8a7a-5408-453a-bb4b-4451e93b52fd0] Transition is timeout
Jul 15 09:05:11 raspberrypi4 WebAppMgr[603]: [] [pmlog] WAM LUNA_API {"APP_ID":"com.luxoft.app.test.svtplay.0","API":"killApp"} reason :

Looks like application spends too long (>10s) in "launching" state and is killed in https://github.com/webosose/sam/blob/8a1443b41a75e23f75cca247b3f010190f439d7e/src/base/RunningApp.cpp#L257 .

If I try to launch the application again soon after it very often succeeds, e.g. the web application only spends 4s in launching state before it goes to foreground state:

Jul 15 09:08:40 raspberrypi4 sam[607]: [I][RunningApp][setLifeStatus][02ca65f6-a470-4b63-aad8-7ad4ffa035800] Changed: com.luxoft.app.test.svtplay.0 (stop ==> splashing)
Jul 15 09:08:40 raspberrypi4 sam[607]: [I][RunningApp][setLifeStatus][02ca65f6-a470-4b63-aad8-7ad4ffa035800] Changed: com.luxoft.app.test.svtplay.0 (splashing ==> splashed)
Jul 15 09:08:40 raspberrypi4 sam[607]: [I][RunningApp][setLifeStatus][02ca65f6-a470-4b63-aad8-7ad4ffa035800] Changed: com.luxoft.app.test.svtplay.0 (splashed ==> launching)
Jul 15 09:08:44 raspberrypi4 sam[607]: [I][RunningApp][setLifeStatus][02ca65f6-a470-4b63-aad8-7ad4ffa035800] Changed: com.luxoft.app.test.svtplay.0 (launching ==> foreground)

Perhaps it loads faster the second time due to web content being cached locally, not sure.

Also not sure that this is something that should be fixed in SAM or in WAM. Or is there e.g. a way to make the web application behave better (say that it should be brought to foreground before loading has finished). Have not found any documentation for how to handle web apps that take a long time to load on https://www.webosose.org yet.

martin-ejdestig commented 4 years ago

Just noticed that the timestamps in the log above when the application fails is weird. It is 09:05:11 both for splashed ==> launching and Transition is timeout which does not make any sense. Not sure what is going on there. Some buffering in log framework?

Anyway, here is a log that shows the application being killed with timestamps that make more sense (launching 10s before timeout is struck and app is killed):

Jul 16 14:54:46 raspberrypi4 sam[610]: [I][RunningApp][setLifeStatus][0c52f033-fd4b-47d3-9587-958481578d360] Changed: com.luxoft.app.test.svtplay.0 (stop ==> splashing)
Jul 16 14:54:46 raspberrypi4 sam[610]: [I][RunningApp][setLifeStatus][0c52f033-fd4b-47d3-9587-958481578d360] Changed: com.luxoft.app.test.svtplay.0 (splashing ==> splashed)
Jul 16 14:54:46 raspberrypi4 sam[610]: [I][RunningApp][setLifeStatus][0c52f033-fd4b-47d3-9587-958481578d360] Changed: com.luxoft.app.test.svtplay.0 (splashed ==> launching)
Jul 16 14:54:56 raspberrypi4 sam[610]: [W][RunningApp][onKillingTimer][0c52f033-fd4b-47d3-9587-958481578d360] Transition is timeout
Jul 16 14:54:56 raspberrypi4 WebAppMgr[613]: [] [pmlog] WAM LUNA_API {"APP_ID":"com.luxoft.app.test.svtplay.0","API":"killApp"} reason :