| freemangordon | dsc_: please consider adding timestamps in the logs | 08:12 |
|---|---|---|
| freemangordon | scratch that, I'll implement it | 08:34 |
| kiva | should Maemo Leste be year 2039 compatible? Has anybody noticed that it is shorter time ti to 32-bit time bug than N900 release date? | 14:16 |
| sicelo | most likely not (fully) compatible yet. Debian has fixed this only recently. | 14:17 |
| kiva | Actually is that reason why default clock app crash in Pinephone, when try change time? | 14:19 |
| Wizzup | that seems unlikely | 14:21 |
| dsc_ | freemangordon: https://github.com/maemo-leste/conversations/commit/a1253465beba6f1dbd5b814caec1acb005598dad | 14:28 |
| dsc_ | this removes AccountChannelPtr too, which is suppose to linger around | 14:30 |
| dsc_ | I can get rid of AccountChannelPtr but it requires some changes to Tp | 14:30 |
| dsc_ | and possibly affects other parts of conversations too | 14:30 |
| dsc_ | the reason AccountChannelPtr stays around is to represent a persistent channel that you have not yet joined | 14:31 |
| dsc_ | I talked about this earlier how architecturally the config stuff should be removed from lib/tp.cpp, I was talking about this | 14:32 |
| dsc_ | I think 0.7.15 will segfault due to this commit | 14:34 |
| dsc_ | yes, after leaving a groupchat it will segfault | 14:35 |
| dsc_ | so I will work on tp for the next few days and untangle some stuff | 14:37 |
| freemangordon | dsc_: ok, great, just keep in mind I am MIA for 2 weeks starting Friday. Please do not break conversations too much while I am on holiday :p | 14:38 |
| dsc_ | the changes required to make lib/tp.cpp more self-contained will be large and breakage might be present | 14:39 |
| dsc_ | we can choose to keep the current arch for now and I do an easy fix | 14:39 |
| freemangordon | yeah, I understand | 14:39 |
| freemangordon | I was kidding anyways | 14:39 |
| dsc_ | ok :) | 14:39 |
| dsc_ | yes ill do my best ^^ | 14:39 |
| freemangordon | but won;t be able to either test or make fixes | 14:40 |
| freemangordon | dsc_: https://pastebin.com/xwcPJV0j | 15:15 |
| freemangordon | something is broken when saving date_last_message | 15:15 |
| freemangordon | I put some more traces | 15:16 |
| freemangordon | this https://pastebin.com/SknCviHd, should not affect the result | 15:18 |
| freemangordon | I wonder if channel gets properly inited on logoff/logon | 15:18 |
| freemangordon | like, I see configSave(), but no configRead() | 15:19 |
| dsc_ | is `channels[channel_str]->date_last_message;` ever set? | 15:20 |
| freemangordon | channels[channel_str]->date_last_message = epoch; | 15:20 |
| freemangordon | lemme push, you'll see | 15:20 |
| dsc_ | unsure if I should look because ill probably be removing AccountChannel today | 15:21 |
| freemangordon | ok | 15:22 |
| freemangordon | still, I'll push the logger changes | 15:22 |
| dsc_ | is the issue its not being saved to cfg? | 15:22 |
| freemangordon | rather it is not read back | 15:22 |
| freemangordon | test case is: | 15:22 |
| freemangordon | receive remote message, but not read it (so it is not marked as read on the server) | 15:23 |
| freemangordon | reconnect the account (so unread messages are delivered as scrollback) | 15:23 |
| freemangordon | that unread message is duplicated, because timestamp check fails, as date_last_message is 0 (as seen oin the lofs) | 15:24 |
| freemangordon | *logs | 15:24 |
| dsc_ | right | 15:24 |
| freemangordon | I suspect channel settings are not re-read on logon | 15:24 |
| dsc_ | yes | 15:25 |
| dsc_ | AccountChannelPtr(new AccountChannel); | 15:25 |
| dsc_ | look for this one | 15:25 |
| freemangordon | yeah, I understand | 15:25 |
| dsc_ | right | 15:25 |
| freemangordon | but now you're going to remove that, I see no reason to fix it | 15:25 |
| dsc_ | and configRead() is only in the constructor | 15:26 |
| dsc_ | of TelepathyAccount | 15:26 |
| freemangordon | mhm | 15:26 |
| freemangordon | I saw that | 15:26 |
| dsc_ | will fix :) | 15:26 |
| freemangordon | great! ok, lets push few fixes to haze and purple-fb | 15:27 |
| Wizzup | so from my pov apart from the random audio issues where the kernel doesn't set what it should set in calls, the voicecall mgr stuff is working well on my d4 | 15:56 |
| Wizzup | I'll make a PR with the various fixes | 15:56 |
| Wizzup | but we still need to figure out the kernel audio issues and then we could move a conversations release to stable too | 15:56 |
| Wizzup | (and then we can more easily break -devel) | 15:57 |
| Wizzup | I just don't know how to go around debugging this kernel issue | 15:57 |
| Wizzup | uvos: would you agree that switching PA UCM profiles back to HiFi and back to Phone Call should ideally set the regs up properly again? | 15:57 |
| freemangordon | Wizzup: If we are to release conversations to stable, the bug I reported ^^^ shall be fixed | 15:58 |
| freemangordon | but it is up to you and dsc_ to decide | 15:59 |
| Wizzup | ok, I don't know what the bug is that you mean, but keep in mind that current conversations stable is like months behind devel | 15:59 |
| Wizzup | like it'll probably segfault when going online/offline or something | 15:59 |
| Wizzup | (in some edge case) | 15:59 |
| Wizzup | in any case it's all moot until we figure out the kernel audio issue | 15:59 |
| Wizzup | I suppose we could decide to debug this, or we can go straight to 6.6 and try to figure out why it doesn't work there | 16:00 |
| freemangordon | no, it will not update last message received timestgamp going offline->online, leading to duplicated scrollback of the unread messages | 16:00 |
| dsc_ | i can aim for a stable next week | 16:00 |
| dsc_ | if needed | 16:00 |
| dsc_ | wait, what day is it even... | 16:00 |
| freemangordon | wednesday | 16:00 |
| dsc_ | thanks ;x | 16:00 |
| freemangordon | :) | 16:00 |
| Wizzup | ok | 16:01 |
| Wizzup | well, any suggestions on how to try to debug the call issues I would appreciate | 16:01 |
| dsc_ | yes I think we can do a stable soon | 16:01 |
| Wizzup | since it's also (a similar bug) the only blocker for 6.6 or 6.8 (i forget) kernel | 16:01 |
| freemangordon | Wizzup: I guess tmlind is to the rescue :) | 16:02 |
| Wizzup | I am not sure if he has a lot of time recently | 16:02 |
| Wizzup | also for 6.1 (which is not pretty old) it might not be that worth it | 16:02 |
| Wizzup | which is now* | 16:03 |
| Wizzup | I guess we would need some trace of all alsa state changes or something | 16:06 |
| Wizzup | maybe cpcap_input_*_mux_set_enum or something will override what's currently set during voice call | 16:11 |
| Wizzup | must be some race with userspace somehow | 16:16 |
| Wizzup | uvos: should I not see 'VOICE CALL' in dmesg whenever I switch ucm in pavucontrol? | 16:31 |
| freemangordon | AFAIK this is logged by the modem driver when modem reports incoming call | 16:32 |
| Wizzup | no this happens in cpcap_voice_call | 16:33 |
| freemangordon | but don;t quote me on that one | 16:33 |
| freemangordon | lemme grep | 16:33 |
| Wizzup | sound/soc/codecs/cpcap.c | 16:33 |
| Wizzup | no need to grep | 16:33 |
| Wizzup | the problem is that bits CPCAP_BIT_MB_ON1R and CPCAP_BIT_MB_ON1L are somehow unset when we are in the actual call | 16:33 |
| Wizzup | and from my understanding | 16:34 |
| Wizzup | modem -> ofono -> sphone acts on voice call -> starts ringing -> when picked up -> sphone tells PA to switch to voice call UCM | 16:34 |
| Wizzup | and this switch I believe is what should trigger all the right settings to be set, including the DAPM hack for which we print 'VOICE CALL" | 16:34 |
| Wizzup | but apparently switching UCM *does not* trigger cpcap_voice_call | 16:35 |
| freemangordon | maybe put printk in cpcap_voice_set_tdm_slot | 16:37 |
| Wizzup | cpcap_voice_set_tdm_slot is what calls cpcap_voice_call | 16:37 |
| freemangordon | mhm | 16:37 |
| Wizzup | yeah so you think this prevents this from being set when we're not in a call? | 16:37 |
| Wizzup | there's so much jargin in alsa kernel land it's mind boggling :( | 16:38 |
| Wizzup | jargon | 16:38 |
| freemangordon | but cpcap_voice_set_tdm_slot can return before calling cpcap_voice_call | 16:38 |
| Wizzup | yes exactly | 16:38 |
| Wizzup | but what is tdm slot even | 16:38 |
| freemangordon | TDM is time division multiplexing, but what it means in this context I have NFC | 16:38 |
| Wizzup | well I guess the function makes it pretty clear | 16:39 |
| Wizzup | so somehow in the timeslot setting we also actually set up the call regs | 16:39 |
| Wizzup | I am not sure why cpcap_voice_set_tdm_slot even needs to check if we are in a call, I guess because it needs to be able to unset somehow? | 16:40 |
| freemangordon | I would trace if cpcap_voice_set_tdm_slot() gets called at all | 16:40 |
| Wizzup | because us switching UCM from voice call to HiFi or vice versa isn't related to this level | 16:40 |
| Wizzup | well I know that during calls I typically see 'VOICE CALL' | 16:40 |
| freemangordon | so, if it is called but returns early, then yo should check why | 16:41 |
| Wizzup | I was just hoping I wouldn't have to keep calling myself just to see how some of this works | 16:41 |
| freemangordon | just put printk() every other source line | 16:41 |
| Wizzup | also I wonder if those errors are actually logged | 16:41 |
| Wizzup | or if some alsa debug value is missing | 16:41 |
| freemangordon | dev_err() is logged | 16:41 |
| freemangordon | but I don;t see error printed on calls to regmap | 16:42 |
| freemangordon | not sure if regmap will print error | 16:42 |
| Wizzup | well this is called from alsa code | 16:42 |
| Wizzup | see static const struct snd_soc_dai_ops cpcap_dai_voice_ops | 16:42 |
| freemangordon | yes, I know | 16:43 |
| freemangordon | thats why I said to check if it is called at all when voice fails | 16:43 |
| Wizzup | and yes it is | 16:43 |
| Wizzup | since 'VOICE CALL' is always printed | 16:43 |
| freemangordon | ah | 16:44 |
| Wizzup | and there's some race going on | 16:44 |
| freemangordon | sorry, my bad | 16:44 |
| Wizzup | so I think sound/soc/codecs/motmdm.c calls snd_soc_dai_set_tdm_slot | 16:44 |
| Wizzup | so maybe this has a better clue | 16:44 |
| freemangordon | I was left with the impression that sometimes there is no "VOICE CALL" message | 16:44 |
| Wizzup | ha the return value of motmdm_enable_primary_dai is ignored | 16:44 |
| Wizzup | freemangordon: I will have to triple check, but I am pretty sure that is always set | 16:45 |
| freemangordon | ok, ok | 16:45 |
| Wizzup | in codecs/motmdm.c see: | 16:45 |
| Wizzup | if (enable) motmdm_enable_primary_dai(ddata->component); | 16:45 |
| Wizzup | else motmdm_disable_primary_dai(ddata->component); | 16:45 |
| Wizzup | so it ignores the error tha we bubble up all the way from regmap sets | 16:45 |
| Wizzup | I think we should fix that regardless | 16:45 |
| freemangordon | why it is called at all from motmdm? isn;t ALSA supposed to call it | 16:45 |
| Wizzup | motmdm is the codec, so I guess that is part of alsa | 16:46 |
| Wizzup | I don't know what the graph of what uses what is here | 16:46 |
| freemangordon | but it shoudl not call that function directly, no? | 16:46 |
| freemangordon | I am as lost as you are perhaps | 16:46 |
| Wizzup | the codec seems to find ngsm serdev and see what the call state is | 16:47 |
| Wizzup | this is managed from /* Read the voice status from dlci1 and let user space handle rest */ | 16:47 |
| Wizzup | static int motmdm_init_voice_dlci(struct motmdm_driver_data *ddata) | 16:47 |
| Wizzup | it seems | 16:47 |
| Wizzup | well and of course motmdm_soc_probe | 16:47 |
| freemangordon | well, I remember motmdm handling calls state | 16:47 |
| freemangordon | motmdm_enable_primary_dai() is called on incoming call, IIRC | 16:48 |
| Wizzup | the motmdm codec also registers dtmf/call noise cancel and call volume | 16:48 |
| freemangordon | see motmdm_voice_get_state | 16:49 |
| Wizzup | yes, this is what enables or disables the dai | 16:49 |
| Wizzup | so I guess there is no way to trigger it from userspace then | 16:50 |
| freemangordon | mhm | 16:50 |
| Wizzup | or perhaps there is, just not with our ucm | 16:50 |
| Wizzup | I suspect there is some race not that voicecall-manager is in play, and somehow the delay makes it worse | 16:50 |
| Wizzup | like if the ucm is set before or after the kernel performs all of this | 16:50 |
| freemangordon | sounds plausible | 16:52 |
| freemangordon | I wonder if we shall remove the call to snd_soc_dai_set_tdm_slot() and somehow tie it to UCM | 16:54 |
| Wizzup | we'd need some mixer/control in alsa to toggle this | 16:54 |
| freemangordon | yes, I know | 16:55 |
| Wizzup | there's also the whole DAPM hack that we have to do anything, which I still don't really understand, but I think the point is that because the audio does not go through userspace routing, alsa decides that we don't actually use/need it | 16:55 |
| Wizzup | and we haven't found a way to tell alsa not to do it other than force-enable dapm pins/paths | 16:55 |
| freemangordon | which obviously does not work properly | 16:56 |
| Wizzup | well it works ok for us now | 16:56 |
| Wizzup | but yes it's not ideal | 16:56 |
| freemangordon | as voice calls are not the only issue we have | 16:56 |
| freemangordon | no, mafw suffers as well | 16:56 |
| Wizzup | mafw suffers a lot more than other HiFi though | 16:56 |
| Wizzup | so maybe best to not conflate the issues | 16:56 |
| Wizzup | also killing mafw-renderer makes it work again when it's restarted, so there's other stuff going on there | 16:57 |
| freemangordon | I doubt mafw does something bad, as it uses PA | 16:57 |
| Wizzup | fine, but mpv with pa usually works fine after audio call | 16:57 |
| Wizzup | and this is not the result of DAPM I am quite sure | 16:57 |
| freemangordon | ok | 16:57 |
| Wizzup | it could be however that the tdm from before the call is not saved | 16:57 |
| Wizzup | and this might throw off PA and then everything else | 16:57 |
| freemangordon | but commenting out line 549 in motmdm makes it working properly | 16:58 |
| freemangordon | besides that call audio is funny | 16:58 |
| Wizzup | what tag/branch are you on | 16:58 |
| freemangordon | I guess master, lemme check | 16:58 |
| Wizzup | 549 for me is: | 16:58 |
| Wizzup | struct cpcap_audio *cpcap = snd_soc_component_get_drvdata(component); | 16:58 |
| Wizzup | oh wait, wrong file :) | 16:58 |
| Wizzup | 549 for me is: | 16:58 |
| Wizzup | strncmp(state, "1,4,0", 5) || /* incoming call */ | 16:58 |
| Wizzup | well, !strncmp | 16:59 |
| freemangordon | yes, that one | 16:59 |
| Wizzup | I think this just means that by completely nerfing call audio you don't run into the problem | 16:59 |
| freemangordon | mhm | 16:59 |
| freemangordon | there *is* audio though | 17:00 |
| Wizzup | actually, we could look at this soon if you want | 17:00 |
| Wizzup | we can check the CPREG_REG_CDI reg | 17:00 |
| freemangordon | just sounds funny for both sides | 17:00 |
| Wizzup | and see what the time stuff is set to | 17:00 |
| Wizzup | and see if it gets set back properly after the call | 17:00 |
| Wizzup | my bet is no | 17:00 |
| freemangordon | because frequency seems off | 17:00 |
| Wizzup | and this is why you have the issues | 17:00 |
| freemangordon | right | 17:00 |
| Wizzup | like this force samples rates I think | 17:00 |
| Wizzup | see cpcap_voice_set_tdm_slot's cpcap_set_samprate | 17:01 |
| freemangordon | right | 17:01 |
| Wizzup | there's a bunch of dev_dbg that we're missing out on for sound/soc/codecs/cpcap.c | 17:02 |
| Wizzup | wonder how we can get those | 17:03 |
| Wizzup | like: | 17:03 |
| Wizzup | dev_dbg(component->dev, "HiFi setup HW params: rate=%d", rate | 17:03 |
| Wizzup | return cpcap_set_samprate(cpcap, CPCAP_DAI_HIFI, rate); | 17:03 |
| freemangordon | I think they are compiled-out | 17:03 |
| Wizzup | I always forget how this works :) | 17:03 |
| Wizzup | but it seems like component->dev might be what we could enable/filter on in debug msgs | 17:03 |
| Wizzup | https://stackoverflow.com/questions/50504516/enable-linux-kernel-driver-dev-dbg-debug-messages | 17:04 |
| freemangordon | I don;t think we have CONFIG_DYNAMIC_DEBUG=y | 17:04 |
| Wizzup | maybe we should... | 17:05 |
| freemangordon | no | 17:05 |
| freemangordon | that'd put too much overhead | 17:05 |
| freemangordon | just compile your kernel | 17:05 |
| freemangordon | that's what I do when developing | 17:05 |
| Wizzup | it's very inconvenient when you have 5-6 devices but I suppose | 17:06 |
| freemangordon | or, simply change dev_dbg to printk or dev_err :) | 17:06 |
| Wizzup | I don't think there'd be a lot of overhead at all | 17:06 |
| Wizzup | but ymmv | 17:06 |
| Wizzup | internet seems to say the overhead is quite low | 17:11 |
| Wizzup | it also seems to be default on for most distros | 17:12 |
| freemangordon | what about memory overhead? | 17:15 |
| freemangordon | most distros do not run on n900 :) | 17:15 |
| Wizzup | I doubt there would be any? | 17:15 |
| Wizzup | what else memory would need to be stored? | 17:15 |
| Wizzup | 8 chars for filename? | 17:16 |
| freemangordon | * number of files | 17:16 |
| Wizzup | still nothing | 17:16 |
| freemangordon | well, I think we shall not enable unnecessary features that are used rarely | 17:17 |
| freemangordon | but... | 17:17 |
| freemangordon | I know it is inconvenient, but compiling the kernel is not that hard and you have to do it anyways when making changhes | 17:17 |
| Wizzup | I don't mind compiling my own kernel, it's just nice to make our (earlt debugging) life easier | 17:18 |
| Wizzup | it's not just compiling, it's also shutting off,removing sd card, copying dtb/dts, kernel, modules to the right path, depmod -a | 17:18 |
| Wizzup | and booting again | 17:18 |
| Wizzup | but yeah. | 17:18 |
| freemangordon | no, why? | 17:18 |
| freemangordon | I copy zImage/modules through ssh | 17:18 |
| freemangordon | and just reboot | 17:19 |
| freemangordon | you don;t need another dtb usually | 17:19 |
| freemangordon | just zImage/modules | 17:19 |
| Wizzup | still a lot of effort, more than just 'make' | 17:19 |
| freemangordon | and you cannot avoid it | 17:20 |
| Wizzup | with dynamic debug you can ;) | 17:20 |
| freemangordon | no, you can only get traces | 17:20 |
| freemangordon | but can fix nothing :) | 17:20 |
| Wizzup | yes, this helps a ton with reporting issues and even having users debug stuff for/with us | 17:21 |
| Wizzup | but nevermind, I don't care enough to continue going down this path | 17:21 |
| freemangordon | me neither | 17:21 |
| freemangordon | so if you decide this shall be enabled... ok | 17:21 |
| freemangordon | I am just sharing my opinion | 17:22 |
| freemangordon | dsc_: btw, what about just getting the timestamp of the last message for that channel in rtcom db instead of storing it in QSettings? | 17:34 |
| d4dsc | tp.cpp is not aware of the last rtcom entry so it would need to query for it | 17:56 |
| d4dsc | sure, could do | 17:56 |
| d4dsc | it would query for every incoming message, could cache it | 17:57 |
| d4dsc | query itself is ro | 17:58 |
| d4dsc | *is grouped by group-uid and then order by timestamp | 17:58 |
| Wizzup | uvos: sicelo: is there a reason our current devel kernel is 6.1.67 but our maemo-6.1.y branch is on 6.1.80? | 18:18 |
| Wizzup | ah, I see, the dtses do not build.. | 18:21 |
| Wizzup | [ 418.496276] mot-mdm6600-codec 4806a000.serial:modem:audio-codec@2: motmdm_send_command: sending U1848AT+CLVL=0 | 20:31 |
| Wizzup | [ 418.520446] mot-mdm6600-codec 4806a000.serial:modem:audio-codec@2: motmdm_receive_data: received: +CLVL:OK | 20:31 |
| Wizzup | ok that works :) | 20:31 |
| Wizzup | uvos: pushed to vcm-fixes, this fixes all issues except for sound, which I am looking at now. | 20:37 |
| Wizzup | uvos: on sphone that is | 20:37 |
| Wizzup | https://github.com/maemo-leste/sphone/pull/7 | 20:38 |
| Wizzup | I can't believe this worked in sphone every time, hrm | 20:47 |
| Wizzup | tmlind: uvos: freemangordon: here are some dmesg logs from my droid 4 when I get called, I called myself three times and made three different logs of the relevant parts: https://wizzup.org/dirlist/maemo-leste/call-dmesg-logs/ | 20:49 |
| Wizzup | That is done using: | 20:49 |
| Wizzup | echo 'file cpcap.c +p' > /sys/kernel/debug/dynamic_debug/control | 20:49 |
| Wizzup | echo 'file motmdm.c +p' > /sys/kernel/debug/dynamic_debug/control | 20:49 |
| Wizzup | and then using dmesg -w, and I cut off the timestamps to make diffing easier | 20:49 |
| Wizzup | There's a lot of suspicious stuff there... | 20:50 |
| Wizzup | the main thing to note is that apparently we handle ciev=1,4,0 twice in every log, but in the one where it doesn't work, it comes a lot later | 20:52 |
| Wizzup | that is: | 20:52 |
| Wizzup | mot-mdm6600-codec 4806a000.serial:modem:audio-codec@2: motmdm_voice_get_state: ciev=1,4,0 | 20:52 |
| Wizzup | When it is working we got from 1,4,0 to 1,2,0 to 1,0,0 (done) | 20:53 |
| Wizzup | when I get no good audio it goes from 1,4,0 to 1,2,0 to 1,0,0 to 1,4,0 to 1,2,0 and again to 1,2,0 | 20:53 |
| Wizzup | And I can assure you I didn't call myself twice | 20:53 |
| Wizzup | I'm confused | 20:54 |
| Wizzup | Also the problem is extra apparent when you see the 'VOICE CALL 1' goes to 'VOICE CALL 0' and again to 'VOICE CALL 1' | 20:54 |
| Wizzup | and the same happens with HiFi : it's mute 0 (ringtone), then to 1 (muted), but basicaly it immediately goes back to mute 0 (unmuted) | 20:55 |
| Wizzup | I don't know if this is userspace doing something weird but ... it's quite strange | 20:55 |
| Wizzup | I will add n_gsm.c to dynamic debug too | 21:15 |
| Wizzup | great, with n_gsm.debug set to 255 I can't reproduce it anymore so far | 22:05 |
| Wizzup | here are some new logs with n_gsm enabled: https://wizzup.org/dirlist/maemo-leste/call-dmesg-logs/new/ | 22:19 |
| Wizzup | n_gsm debug enabled* | 22:19 |
| Wizzup | here there's only 'VOICE CALL' 1/0 once for every session | 22:21 |
| Wizzup | freemangordon: got a suggestion for a name for our dialer? | 22:47 |
| Wizzup | rtcom-dialer? | 22:48 |
| Wizzup | in fremantle it's rtcom-call-ui | 22:48 |
| Wizzup | but that's the actual binary | 22:48 |
| freemangordon | Wizzup: sorry, just get home, will read the logs tomorrow | 23:01 |
| Wizzup | all good | 23:01 |
Generated by irclog2html.py 2.17.0 by Marius Gedminas - find it at https://mg.pov.lt/irclog2html/!