**** BEGIN LOGGING AT Thu Jun 27 02:59:57 2019 Jun 27 06:10:28 Morning! Jun 27 06:27:12 Morning! Jun 27 07:36:49 Tofe: This one is pending ;) https://github.com/webOS-ports/nodejs-module-webos-sysbus/pull/5 Jun 27 07:37:14 Herrie: merged :) Jun 27 07:37:17 Thnx :) Jun 27 07:37:26 Still doesn't solve any of the Calendar or Email issues though :S Jun 27 08:46:24 Tofe: Thnx Jun 27 08:46:31 no pb **** BEGIN LOGGING AT Thu Jun 27 11:55:06 2019 Jun 27 13:05:45 Tofe: I think I might have part of the issue tracked down... Jun 27 13:07:43 I.e. The problem might have been there for a longer time, so it's not a complete solution yet, but might help us slightly. There was this change in activitymanager: https://github.com/openwebos/activitymanager/commit/cf765b1997aa2cf65e327d4cd55634e187707bc5 Jun 27 13:10:11 Which then requires https://github.com/webOS-ports/mojomail/blob/webOS-ports/webOS-OSE/imap/src/commands/DeleteActivitiesCommand.cpp#L46 to pass the required fields which I doubt it actually does because I sometimes get Error: palm://com.palm.imap/accountEnabled {"accountId":"LBHLLf0G2G+","capabilityProviderId":"com.palm.imap.mail","enabled":false}: 'details flag' must be specified (MojErr Jun 27 13:10:11 22) -- /usr/src/debug/mojomail-imap/2.0.0-99+gitAUTOINC+d3a1f366d5-r0/git/imap/src/commands/DeleteActivitiesCommand.cpp:54 at Object.create Jun 27 13:10:30 So we'd need to add some logging to see what's actually in payload Jun 27 13:20:40 Still a mystery why this worked previously but well ;) Jun 27 13:20:49 Because we had that commit in our activitymanager as well Jun 27 13:25:17 And there are quite some bits that call getDetails for example with only "current" and "internal" while there should be "details" as well ;) Jun 27 13:36:04 Actually seems Garfonso had issues in the past as well :P https://github.com/webOS-ports/org.webosports.update/blob/master/service/javascript/utils/activities.js#L53 Jun 27 13:36:13 "//This currently gives bad exceptions and some kind of timeout in OWO. ActivityManager not working??? :(" Jun 27 13:46:24 Herrie: that could be a good lead yes Jun 27 13:47:51 Seems actually Garfonso addressed some in the past already, passing in the "current" and "internal" flags for the getDetails as per https://github.com/webOS-ports/mojoservice-frameworks/commit/0830163fee42a5a351ea5a478c8f246ea17963e4 Jun 27 13:48:07 But for the "list" which is not used that often seems that calls were never really updated Jun 27 13:50:57 ok Jun 27 13:54:37 Though it seems there's an actual bug as well in OSE activitymanager: https://github.com/webosose/activitymanager/issues/2 Jun 27 13:54:52 EricBlade: Any update on that one by any chance? Jun 27 13:57:13 I guess that one could be tracked down by adding some logging to: https://github.com/webosose/activitymanager/blob/dd631ba54d8970545ccb284ee35bbcd11afb2441/src/activitymanager/activity/ActivityManager.cpp#L97 Jun 27 14:29:02 Tofe: Can you have a look into the C++ bits for getDetails in ActivityManager? I.e. add some logging to see why the getDetails doesn't work like it should? Jun 27 14:39:05 I'll try and see if I can add some debugging to mojomail at my end to track the issue down there Jun 27 14:47:18 Herrie: can do -- when home :) Jun 27 15:06:45 Are you at home or travelling in general :P ? Jun 27 16:59:20 I'm home now :) I was just at work during the day :p Jun 27 16:59:44 (and with a crazy week...) Jun 27 17:00:28 Herrie: so, how can I reproduce the "details" issue? Jun 27 17:11:18 Herrie: for the moment I've just added this: https://github.com/openwebos/activitymanager/compare/master...webOS-ports:tofe/webOS-OSE?expand=1 Jun 27 17:31:29 Tofe: Well you can see the issue in activitymanager Jun 27 17:32:00 With: luna-send -n 1 -f luna://com.webos.service.activitymanager/getManagerInfo '{}' Jun 27 17:32:07 And then just pick one of the activities there Jun 27 17:32:29 ok Jun 27 17:32:41 And do "luna-send -n 1 -f luna://com.webos.service.activitymanager/getActivityInfo '{"activityName":"testActivity"}'" Jun 27 17:32:52 btw, you know you can do "PmLogCtl set ActivityManager debug" and then get much more debug infos in the logs Jun 27 17:34:21 Ah, I just got Jun 27 17:33:05 qemux86 ls-hubd[260]: Error: palm://com.palm.service.calendar.reminders/onDBChanged {"unittest":false}: palm://com.palm.activitymanager/complete {"activityId":5,"restart":true,"trigger":{"key":"fired","method":"palm://com.palm.db/watch","params":{"query":{"from":"com.palm.calendarevent:1","where":[{"prop":"_rev","op":">","val":1}],"incDel":true}}}}: Invalid transition: unsatisfied -> complete Jun 27 17:38:27 Or luna-send -n 1 luna://com.palm.activitymanager/list '{"details":true, "internal": true, "subscribers": true, "current": true}' Jun 27 17:38:48 let me see Jun 27 17:40:09 "error":"No such file or directory" Jun 27 17:41:20 Yeah I've seen that too at some places Jun 27 17:41:35 Might be specific activity though Jun 27 17:41:42 I had that for SMS one sometime Jun 27 17:42:00 ok Jun 27 17:42:53 getActivityInfo works with activityId, not activityName Jun 27 17:43:31 I think it's related to the fact that when we list the activities, the name is hold by a property named "name", not "activityName" Jun 27 17:45:40 Well both should work according to: https://github.com/webosose/activitymanager/blob/dd631ba54d8970545ccb284ee35bbcd11afb2441/src/activitymanager/service/ActivityCategoryHandler.cpp#L2320 Jun 27 17:49:23 TOfe: Sorry it should be getActivty that gives this error Jun 27 17:50:00 https://github.com/webosose/activitymanager/blob/dd631ba54d8970545ccb284ee35bbcd11afb2441/src/activitymanager/activity/ActivityManager.cpp#L110 Jun 27 17:50:47 one calls the other Jun 27 17:51:34 but in that code I don't understand why they keep two independent registering tables: one per id, one per name Jun 27 17:55:32 There might be some reason :P Jun 27 18:10:54 Tofe: We have some calls in various apps that do: return PalmCall.call("palm://com.palm.activitymanager", "getDetails", {"activityName":name, "current": false, "internal": false}); for example Jun 27 18:22:44 I found out that the reason why it doesn't work with luna-send is that the "BusId" doesn't match Jun 27 18:24:01 Tofe: OK :S Jun 27 18:24:06 But what's a BusID in general? Jun 27 18:24:13 luna-send sends over "BusService" with creator name "com.webos.lunasend-890", and it won't match the creator name of the activity, for instance "com.palm.app.calendar" Jun 27 18:24:19 This extracts name to activityName: https://github.com/webosose/activitymanager/blob/dd631ba54d8970545ccb284ee35bbcd11afb2441/src/am-monitor/Main.cpp#L155 Jun 27 18:24:41 But you can mimic that with luna-send as well? Jun 27 18:24:44 it compares just names only in the case where the bus is an anonymous bus, whatever that means Jun 27 18:24:51 maybe Jun 27 18:24:59 With -a or -m Jun 27 18:25:08 When I added it I had the same result Jun 27 18:25:14 This is also a good example: Jun 27 18:25:26 luna-send -n 1 luna://com.palm.activitymanager/create '{"activity":{"name":"TutorialDashboard","description":"Creating Tutorial Dashboard","schedule":{"start":"2019-06-27 17:38:20Z","interval":"24h","precise":true,"skip":true,"local":true},"callback":{"method":"palm://com.palm.applicationManager/open","params":{"id":"com.palm.systemui","params":{"action":"launchTutorialDashboard","metad Jun 27 18:25:26 ata":{"count":1}}}}},"start":true}' Jun 27 18:25:30 yep, works Jun 27 18:25:33 Followed by luna-send -n 1 palm://com.palm.activitymanager/getDetails '{"activityName":"TutorialDashboard"}' Jun 27 18:25:35 (with -a ) Jun 27 18:26:00 I'll indicate it in the github issue Jun 27 18:26:16 When I use "luna-send -n 1 palm://com.palm.activitymanager/getDetails '{"activityId":707, "current": true, "internal": true}'" it works Jun 27 18:26:25 But with the activityName not Jun 27 18:29:32 Herrie: what's the creator appId you get, with the working getDetails ? Jun 27 18:30:29 you'll have to use that with "-a" when using activityName Jun 27 18:30:43 com.webos.lunasend-950 Jun 27 18:30:47 I just luna-send this one Jun 27 18:30:55 Was an example from systemui that I found Jun 27 18:31:39 use -a "com.webos.lunasend-950" then Jun 27 18:32:07 luna-send creates a new appId each time, and I think it gets in the way of how getDetails works Jun 27 18:33:04 To be frank I don't understand why the creator plays such an important role there; maybe they use it as a namespace to avoid clash of names Jun 27 18:33:32 but then it should be easier to specify it in the getDetails call Jun 27 18:33:58 OK for the one created with luna-send I need to send with -m for it to work Jun 27 18:34:29 For info, here's how a registering looks like: Jun 27 18:34:56 [Activity 21] Registering as appId:com.palm.launcher/"com.palm.launcher" Jun 27 18:35:12 pr Registering as serviceId:com.palm.service.calendar.reminders/"onDBChanged_0" Jun 27 18:35:14 or* Jun 27 18:35:33 The problem is that it seems to fail to register SOME activity, but I'm not sure which one :S Jun 27 18:35:40 appId means you'll need "-a", serviceId you'll need "-m" Jun 27 18:35:45 Yes Jun 27 18:35:49 That's what I figured Jun 27 18:37:28 And there are about 200 of them Jun 27 18:37:42 yep Jun 27 18:37:50 https://paste.ubuntu.com/p/xGbgtsDjHg/ for my early log during boot Jun 27 18:37:57 For calendar we need: https://bpaste.net/show/a55fa7744461 Jun 27 18:38:03 But we don't have them all it seems Jun 27 18:38:53 nope Jun 27 18:38:56 I'm missing calendar.reminders.wake for example Jun 27 18:41:32 How do you get so much logging and where? Jun 27 18:41:41 I don't see this much, mine is a lot more limited it seems Jun 27 18:42:05 BTW novaldex brought http://issues.webos-ports.org/ back online today :D Jun 27 18:42:17 Email still needs to be sorted so we get a reminder, but it's a good start :) Jun 27 18:44:02 I added "ExecStartPost=/usr/bin/PmLogCtl set ActivityManager debug" in /lib/systemd/system/activitymanager.service Jun 27 18:44:13 then I grep /var/log/messages* Jun 27 18:44:25 Ah ok :) Jun 27 18:44:28 That's helpful :) Jun 27 18:45:25 do we know where "$activity":{"activityId":24} comes from ? $activityId is forbidden now it seems Jun 27 18:45:32 "$activity" I mean Jun 27 18:46:36 Well there are various places where we have $activity Jun 27 18:47:04 But I'm not 100% sure $activity is the issue Jun 27 18:47:24 Because we have some with $activity that seem to succeed Jun 27 18:47:50 ah Jun 27 18:49:38 well it's not in http://webostv.developer.lge.com/api/webos-service-api/db/?wos_flag=batch#batch for sure Jun 27 18:50:22 Give me 10-15 mins Jun 27 18:50:38 Children bedtime Jun 27 18:50:49 we have plenty of time Jun 27 19:00:53 Tofe: Well for example the initial call to update the icon of the app (which I think works (i.e. it gets set, then blanked, then re-set by a new activity) Jun 27 19:01:43 https://github.com/webOS-ports/core-apps/blob/webOS-ports/master/com.palm.app.calendar/app/AppIcon.js#L98 Jun 27 19:02:10 but that's not a db8 call Jun 27 19:02:21 (and bad example, there no $activity actually here :) ) Jun 27 19:06:47 And this one? https://github.com/webOS-ports/nodejs-module-webos-service/blob/master/lib/service.js#L161 Jun 27 19:06:55 That's still used in OSE nowadays as well Jun 27 19:07:40 flowmanager and rosbridge (recently introduced) use nodejs-module-webos-service Jun 27 19:08:06 this one is a candidate yes Jun 27 19:09:02 https://github.com/webosose/activitymanager/blob/master/src/activitymanager/service/Subscription.cpp#L98 Jun 27 19:09:35 https://github.com/webosose/activitymanager/blob/master/src/activitymanager/activity/Activity.cpp#L1462 Jun 27 19:10:45 And https://github.com/webosose/activitymanager/blob/master/src/activitymanager/activity/callback/ActivityCallback.cpp#L59 Jun 27 19:10:58 Just GitHub search doesn't like "$activity" but local grep works :P Jun 27 19:11:59 :) Jun 27 19:12:48 The way I understood is $activity is returned by another activity Jun 27 19:13:03 Which can then be used as input for a new activitymanager call Jun 27 19:13:22 But I suspect our initial call somehow fails hence there's no $activity and we see what we see in the logs Jun 27 19:13:32 At least that's my theory Jun 27 19:15:05 but isn't the issue that '$activity' is there while it shouldn't? Jun 27 19:15:15 I'm not sure about that Jun 27 19:15:20 It could be Jun 27 19:26:22 It comes from here in general: where it does the batch call: https://github.com/webOS-ports/loadable-frameworks/blob/webOS-ports/master/calendar/javascript/event-manager.js#L1274 Jun 27 19:27:10 It first creates a watch, when the watch fires it wants to execute the batch Jun 27 19:27:21 L1369 Jun 27 19:27:26 so... DB.execute inserts $activity? Jun 27 19:28:39 That's my guess Jun 27 19:29:10 See this log: https://bpaste.net/show/da55039b578e Jun 27 19:29:21 The query there is compiled with the code I just linked above ;) Jun 27 19:30:06 I grepped around in the image for eventDisplayRevset Jun 27 19:30:19 And this is the only relevant place. Rest is in mock and tests folders Jun 27 19:30:41 now where does DB.execute lead us... nodejs? Jun 27 19:31:11 DB.execute at some point will be com.palm.db/batch ;) Jun 27 19:32:26 not directly, it inserts $activity somewhere Jun 27 19:33:15 No $activity comes back from the earlier activity that was run. The watch and/or query in this case Jun 27 19:33:23 Those return $activity object Jun 27 19:33:27 ah ok Jun 27 19:33:31 At least that's my understanding Jun 27 19:34:48 THere was a link somewhere in documentation but I cannot find it now.. Jun 27 19:34:55 $activity is hard to search for it seems :P Jun 27 19:35:56 :) Jun 27 19:36:14 http://webosose.org/develop/ls2-api/ls2-api-reference/com-webos-service-activitymanager/ Jun 27 19:36:16 Do Expand All Jun 27 19:36:24 And you'll see 2 references to $activity Jun 27 19:36:59 $activity Optional Object: Activity Jun 27 19:36:59 Acitivity object. Jun 27 19:37:32 It's an object that a subscription returns it seems Jun 27 19:37:54 And that activity has these specs: http://webosose.org/develop/ls2-api/ls2-api-reference/com-webos-service-activitymanager/?wos_flag=object#Activity Jun 27 19:38:54 ok Jun 27 20:16:54 Well that's the question ;) Jun 27 20:17:08 Oops wrong window Jun 27 21:25:10 Tofe: I guess adding the same logging for DB8 might give some clues Jun 27 21:25:14 I get a lot in my logs now Jun 27 21:25:18 Just anyway bedtime for now ;) Jun 27 21:25:22 Another day tomorrow Jun 27 21:32:34 yes, I didn't get further either Jun 27 21:32:48 let's try to sleep **** ENDING LOGGING AT Fri Jun 28 02:59:57 2019