**** BEGIN LOGGING AT Fri Sep 17 02:59:57 2010
Sep 17 03:24:59 <denkenz> holtmann: Have the btio issues been solved?
Sep 17 06:42:09 <kvalo> pessi: ping?
Sep 17 12:06:20 <kvalo> Sep 17 15:02:49 dell-m520 ofonod[20897]: Pcui:> AT+CLCK="SC",0,"1234"\r
Sep 17 12:06:20 <kvalo> Sep 17 15:02:49 dell-m520 ofonod[20897]: Pcui:< \r\n+CME ERROR: SIM PIN required\r\n
Sep 17 12:07:09 <kvalo> now that's strange, I try to enter pin and modem says that pin is required
Sep 17 12:32:06 <pessi> kvalo: CPIN required?
Sep 17 12:32:35 <pessi> denkenz: modemconf is only for guys running maemo
Sep 17 12:33:02 <pessi> kvalo: dns is known problem
Sep 17 12:33:43 <kvalo> pessi: thanks, I'll check CPIN. I'm new with AT commands :/
Sep 17 12:33:52 <kvalo> pessi: ah, good to know about dns
Sep 17 12:33:56 <kvalo> sameo: ^
Sep 17 12:36:34 <kvalo> ah crap, I was using wrong script :)
Sep 17 12:36:42 * kvalo hides in the corner
Sep 17 12:36:50 <kvalo> ..and uses enter pin
Sep 17 12:43:18 <sameo> pessi, kvalo: that's not known to me.
Sep 17 12:45:28 <kvalo> with huawei I get nameservers, so I assume this is n900 specific bug?
Sep 17 12:48:35 <akiniemi> kvalo: n900 gives you no nameservers?
Sep 17 12:49:06 <kvalo> akiniemi: I see them in the connman service, but resolv.conf is empty
Sep 17 12:49:55 <holtmann> kvalo: If you use DNS proxy, then you will never see them.
Sep 17 12:50:07 <sameo> holtmann: he doesn't
Sep 17 12:50:08 <holtmann> The /etc/resolv.conf stays at 127.0.0.1
Sep 17 12:50:37 <holtmann> That is weird then. I have no problem with that. Sounds like a race condition. Does list-contexts from oFono has the nameservers in there.
Sep 17 12:50:41 <kvalo> holtmann: I don't use dns proxy, with huawei I see my operator's servers
Sep 17 12:51:23 <holtmann> Check list-contexts script if oFono reports them correctly.
Sep 17 12:51:58 <kvalo> it has to, because I was able to see them with 'cmcc show saunalahti'. but I'll try again
Sep 17 12:53:36 <kvalo> pessi: btw, I still see two "Elisa" contexts
Sep 17 12:56:08 <kvalo>     [ /isimodem1/context1 ]
Sep 17 12:56:08 <kvalo>         Username = 
Sep 17 12:56:08 <kvalo>         Protocol = ip
Sep 17 12:56:08 <kvalo>         Name = 3G Connection
Sep 17 12:56:08 <kvalo>         Settings = { Interface=gprs0 Netmask=255.255.255.255 Method=static DomainNameServers=193.229.0.40,193.229.0.42, Address=85.156.54.89 }
Sep 17 12:56:10 <holtmann> kvalo: Remove the /var/lib/ofono and start fresh. Latest git repos should not give you double contexts. We fixed that.
Sep 17 12:56:31 <kvalo> holtmann: ok, will try that
Sep 17 12:56:38 <holtmann> So they are there. No idea why ConnMan doesn't like them :(
Sep 17 13:01:12 <kvalo> holtmann: nice, now there's only one context. thanks!
Sep 17 13:02:41 <kvalo> pessi: I see 20 seconds stalls quite often:
Sep 17 13:02:44 <kvalo> 4 bytes from 130.233.224.254: icmp_req=14 ttl=123 time=50.8 ms
Sep 17 13:02:44 <kvalo> 64 bytes from 130.233.224.254: icmp_req=15 ttl=123 time=78.5 ms
Sep 17 13:02:44 <kvalo> 64 bytes from 130.233.224.254: icmp_req=16 ttl=123 time=19015 ms
Sep 17 13:02:44 <kvalo> 64 bytes from 130.233.224.254: icmp_req=17 ttl=123 time=18045 ms
Sep 17 13:03:12 <pessi> kvalo: you use meego on n900 or external n900?
Sep 17 13:03:35 <holtmann> Crappy network, crappy antenna, missing calibration, ...
Sep 17 13:03:35 <holtmann> All of these come to mind ;)
Sep 17 13:03:53 <pessi> or all together ;)
Sep 17 13:03:55 <kvalo> this is middle of nowhere, but coverage is quite good
Sep 17 13:04:02 <kvalo> pessi: external
Sep 17 13:04:42 <pessi> I wonder if we get technology (HSDPA) changes?
Sep 17 13:05:12 <kvalo> pessi: at least older nokia phones were always switching between 2g and 3g in my place
Sep 17 13:05:48 <kvalo> next time I go to the city, I'll test there and see if I get similar symptoms
Sep 17 13:12:21 <holtmann> kvalo: The ISI driver has RAT support. Just lock is down to 2G or 3G.
Sep 17 13:12:41 <holtmann> set-tech-preference
Sep 17 13:13:15 <kvalo> holtmann: cool, I'll try that. thanks
Sep 17 13:15:59 <akiniemi> kvalo: that could be a handover from 3G to 2G
Sep 17 13:17:40 <kvalo> I did set-tech-preference and I haven't seen that 20s stall yet.
Sep 17 13:24:46 <kvalo> pessi, akiniemi: I haven't seen these stalls at all when using cellular data within n900 (ie. normal maemo stuff, no pc connected). it seems that something is very different when using ofono
Sep 17 13:59:52 <kvalo> holtmann: I replied to you about huawei initialisation. do you have any ideas? I have about an hour before I have to go
Sep 17 14:00:32 <denkenz> kvalo: Why is post_online reached with an invalid SIM state?
Sep 17 14:01:17 <kvalo> denkenz: I only see the valid state after I have called sim_inserted()
Sep 17 14:01:47 <denkenz> I'm confused now
Sep 17 14:01:59 <kvalo> maybe it has something to do CFUN like you mentioned yesterday...
Sep 17 14:02:32 <denkenz> So basically you can only get to post_online once the SIM PIN has been entered
Sep 17 14:03:07 <kvalo> this was the case even with sim lock disabled
Sep 17 14:03:17 <kvalo> I'll test it again just to be sure
Sep 17 14:03:45 <denkenz> If that is the case, then the firmware is being stupid
Sep 17 14:03:59 <denkenz> Basically it goes something like this:
Sep 17 14:04:21 <denkenz> You plug in dongle, Real Time OS on dongle starts
Sep 17 14:04:32 <denkenz> udev detects device, oFono signals its existence
Sep 17 14:05:14 <denkenz> At this point, both the Real Time OS and oFono are trying to initialize
Sep 17 14:05:20 <denkenz> So there's a race
Sep 17 14:05:49 <denkenz> Something (the driver) needs to throttle oFono until the modem is truly ready
Sep 17 14:06:16 <denkenz> There are really two paths:
Sep 17 14:06:21 <denkenz> sim pin set, and sim pin not set
Sep 17 14:06:36 <kvalo> let's first worry pin not set case
Sep 17 14:07:26 <denkenz> So the unset case is actually tricky
Sep 17 14:08:09 <denkenz> What you need to do is check CPIN? when powering up the modem
Sep 17 14:08:29 <denkenz> If the PIN is READY, you need to wait until the sim is initialized
Sep 17 14:08:35 <kvalo> denkenz: from huawei.c?
Sep 17 14:08:58 <denkenz> It is a good start for now
Sep 17 14:09:11 <denkenz> We might have to migrate this with a quirk to sim atom driver
Sep 17 14:09:21 <denkenz> But lets get something working reliably
Sep 17 14:09:43 <denkenz> Only after it has been initialized, signal sim_inserted
Sep 17 14:17:28 <denkenz> kvalo: It is still funny that you reach post_online state with an invalid sim state
Sep 17 14:17:31 <kvalo> denkenz: I just sent a mail showing how my state doesn't chagnge
Sep 17 14:17:40 <kvalo> *change
Sep 17 14:17:42 <denkenz> post_online implies IMSI has been read
Sep 17 14:18:31 <kvalo> denkenz: so sim_inserted() somehow triggers my modem to initialise
Sep 17 14:18:39 <denkenz> Has this modem ever gone into sim state 1?
Sep 17 14:19:04 <denkenz> It might be that this particular huawei firmware is weird and only does sim state 1 when it registers to the network
Sep 17 14:19:21 <kvalo> yes, after sometime call to sim_inserted()
Sep 17 14:19:39 <denkenz> sim_inserted doesn't do anything magic
Sep 17 14:19:56 <denkenz> It just tells oFono there's a SIM and it can be queried for CPINs and stuff
Sep 17 14:20:14 <kvalo> ok, I'll try to find what triggers it
Sep 17 14:20:21 <kvalo> netreg stuff then, maybe?
Sep 17 14:20:40 <denkenz> Dunno, check your logs
Sep 17 14:20:55 <denkenz> does SIMST get signaled shortly before/after a CREG notification?
Sep 17 14:21:43 <denkenz> Because that's 8 seconds with an invalid sim state from your Email
Sep 17 14:21:46 <denkenz> That is an eternity
Sep 17 14:22:00 <kvalo> denkenz: I'm not that good with ofono logs :) but let me grep a bit
Sep 17 14:22:57 <denkenz> Actually 2 seconds / timeout, so that's 15+ seconds
Sep 17 14:22:57 <kvalo> Sep 17 17:07:19 dell-m520 ofonod[2331]: Pcui:< \r\n+CRSM: 144,0,"FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF"\r\n\r\nOK\r\n
Sep 17 14:23:00 <kvalo> Sep 17 17:07:19 dell-m520 ofonod[2331]: drivers/atmodem/sim.c:at_crsm_read_cb() crsm_read_cb: 90, 00, 24
Sep 17 14:23:03 <kvalo> Sep 17 17:07:19 dell-m520 ofonod[2331]: Pcui:> AT+CRSM=178,28480,5,4,24\r
Sep 17 14:23:06 <kvalo> Sep 17 17:07:19 dell-m520 ofonod[2331]: Pcui:< \r\n+CRSM: 144,0,"FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF"\r\n\r\nOK\r\n\r\n^SRVST:1\r\n\r\n^MODE
Sep 17 14:23:09 <kvalo> :5,4\r\n\r\n^SIMST:1\r\n
Sep 17 14:23:36 <kvalo> Sep 17 15:43:29 dell-m520 ofonod[21354]: Pcui:> AT+CRSM=178,28480,5,4,24\r
Sep 17 14:23:36 <kvalo> Sep 17 15:43:29 dell-m520 ofonod[21354]: Pcui:< \r\n^SRVST:1\r\n
Sep 17 14:23:36 <kvalo> Sep 17 15:43:29 dell-m520 ofonod[21354]: Pcui:< \r\n^MODE:5,4\r\n\r\n^SIMST:1\r\n
Sep 17 14:24:29 <denkenz> And when does CFUN=1 get sent in these logs?
Sep 17 14:24:51 <kvalo> Sep 17 15:43:28 dell-m520 ofonod[21354]: Pcui:> AT+CFUN=1\r
Sep 17 14:25:10 <denkenz> So 1 second, why are we in an invalid sim state?
Sep 17 14:25:56 <denkenz> Something doesn't add up
Sep 17 14:26:02 <kvalo> Sep 17 17:07:18 dell-m520 ofonod[2331]: Pcui:> AT+CFUN=1\r
Sep 17 14:26:46 <kvalo> what does AT+CFUN=1;+CFUN=5 do?
Sep 17 14:27:00 <kvalo> it's in huawei_enable()
Sep 17 14:27:19 <denkenz> That is pessi's change, basically it is attempting to power on the huawei and put it into offline state
Sep 17 14:27:32 <denkenz> CFUN=5 means rx/tx off
Sep 17 14:27:35 <kvalo> so 5 is offline?
Sep 17 14:27:38 <kvalo> ah, ok
Sep 17 14:27:38 <denkenz> e.g. radio off
Sep 17 14:30:22 <denkenz> So now I'm really confused, is your SYSINFO reporting a different sim state than SIMST?
Sep 17 14:30:28 <denkenz> Or is SIMST getting ignored ;)
Sep 17 14:31:52 <kvalo> I haven't noticed any differences between the two. where did you see that?
Sep 17 14:32:42 <denkenz> I'm just looking at the code, we have:
Sep 17 14:32:43 <denkenz>         /* follow sim state */
Sep 17 14:32:43 <denkenz>         g_at_chat_register(data->pcui, "^SIMST:", simst_notify,
Sep 17 14:32:43 <denkenz>                                                 FALSE, modem, NULL);
Sep 17 14:33:04 <denkenz> and simst_notify should set the sim state to 1
Sep 17 14:33:19 <denkenz> So ~1 second after CFUN=1 we should be AOK
Sep 17 14:33:34 <denkenz> Yet your log shows you polling sim state for 15 seconds and it being 0
Sep 17 14:33:55 <denkenz> (the one in your email reply to ofono ML)
Sep 17 14:34:07 <kvalo> but that's without sim_inserted() call
Sep 17 14:34:30 <kvalo> and hence set_online() won't be called
Sep 17 14:34:38 <kvalo> AFAIK
Sep 17 14:35:05 <denkenz> Yeah, but you still set the internal state variable, no?
Sep 17 14:35:39 <kvalo> what do you mean? I didn't see any SIMST messages in that case.
Sep 17 14:36:10 <denkenz> whoa
Sep 17 14:36:39 <kvalo> I'll send a full log to the ml. what information should I hide? IMSI?
Sep 17 14:37:02 <denkenz> Might be a good idea
Sep 17 14:37:08 <kvalo> anything else?
Sep 17 14:37:25 <denkenz> Your subscriber numbers maybe, if you have them set
Sep 17 14:37:33 <kvalo> ok, thanks
Sep 17 14:38:28 <denkenz> So try taking out CFUN=5 and see if this stuff works normally
Sep 17 14:38:36 <denkenz> I suspect pessi never tested the CFUN=5 change
Sep 17 14:39:33 <kvalo> ok
Sep 17 14:40:33 <pessi> me? testing? naaah
Sep 17 14:41:47 <pessi> and I managed to fish out my huawei modem from junk box and it turned out to be ZTE. same qualcomm crap, I suppose, but not huawei
Sep 17 14:42:02 <denkenz> same quality ;)
Sep 17 14:42:04 <kvalo> pessi: and no huawei is alike :)
Sep 17 14:44:00 <kvalo> yeah, now I get SIMST earlier
Sep 17 14:44:51 <denkenz> Ok, so maybe we have to it like this:
Sep 17 14:45:31 <denkenz> cfun=1, query pin state, if ready, wait until simst:1 then send cfun=5
Sep 17 14:47:03 <pessi> hmph, and where to find a windows pc to say at+zcdrun? all the managers have left 
Sep 17 14:47:07 <kvalo> ok, I'll try that next week. unless someone else is faster :)
Sep 17 14:48:29 <denkenz> kvalo: nod
Sep 17 14:48:40 <kvalo> denkenz: so simst:1, cfun=5 and then sim_inserted()?
Sep 17 14:49:19 <denkenz> kvalo: Probably like simst:1, cfun=5 -> callback, in the callback set_powered(TRUE); sim_inserted(TRUE)
Sep 17 14:49:44 <denkenz> just thinking out loud
Sep 17 14:50:34 <kvalo> I was just about to ask about power. so now I enabled it when simst:0
Sep 17 14:50:58 <kvalo> so you think I should do it on simst:1?
Sep 17 14:51:07 <denkenz> Powered is less important actually
Sep 17 14:51:21 <denkenz> oFono will not do anything until sim_inserted is signaled
Sep 17 14:51:31 <denkenz> However, there's a brief second where your radio is on
Sep 17 14:51:49 <denkenz> so if you're on an airplane and plug in your dongle, that is bad ;)
Sep 17 14:51:58 <kvalo> heh
Sep 17 14:52:58 <kvalo> ok, I now understand this better. thanks for the help
Sep 17 14:53:02 <denkenz> so you can do cfun=1 -> set_powered(true), then sim pin query, simst:1, cfun=5 -> sim_inserted(TRUE)
Sep 17 14:54:25 <kvalo> oh yeah, there's also that 255 state.
Sep 17 14:54:39 <kvalo> that's why I added that polling in the first place
Sep 17 14:54:58 <kvalo> because I don't see any SIMST messages when modem goes from 255 to 0
Sep 17 14:55:11 <denkenz> Yeah, and some huaweis don't even bother reporting SIMST in the first place
Sep 17 14:55:17 <denkenz> I think jprvita's did that
Sep 17 14:55:59 <kvalo> I'll take a look at it first thing monday morning. but have a nice weekend everyone
Sep 17 14:56:22 <denkenz> thanks, you too
Sep 17 14:57:00 <kvalo> thanks, I will :)
Sep 17 17:18:45 <majid> there are few items in the PRD that needs our response -- can you please help me answer them by answer Y or N whether it will be supported by MeeGo 1.2 assumption by end of year
Sep 17 17:19:38 <majid> oops
Sep 17 20:49:25 <Jeevaka> denkenz : few questions on CME and SS error mapping?
Sep 17 20:49:38 <denkenz> yeah?
Sep 17 20:50:34 <Jeevaka> is there any spec which has information on mapping of SS errors specified in 3gpp ts 24.080 to cme errors?
Sep 17 20:51:07 <denkenz> I'm not aware of one
Sep 17 20:54:19 <Jeevaka> then how are the error codes from network are mapped to the the CME errors?
Sep 17 20:54:47 <Jeevaka> for example in CUSD, CCFC cases
Sep 17 20:56:42 <denkenz> Don't know, see error codes in 24.008 and 27.007 and compare them to 24.080
Sep 17 20:57:37 <Jeevaka> i have already compared, there is no one to one match
Sep 17 20:58:21 <denkenz> then falling back to 'no cause can be specified' might be better
Sep 17 20:58:30 <Jeevaka> i think so
Sep 17 20:59:02 <Jeevaka> In AT Modems, I think thats the best way
Sep 17 20:59:35 <denkenz> does isi provide more info?
Sep 17 21:00:10 <Jeevaka> ideally, it should provide
Sep 17 21:01:58 <denkenz> So I suggest we use 'no cause given' at first
Sep 17 21:02:05 <denkenz> And if we find a better way, we fix it
Sep 17 21:03:27 <Jeevaka> isi provides more information
Sep 17 21:04:13 <Jeevaka> ok
Sep 17 21:04:23 <denkenz> Yeah, ISI is overall a better protocol and gives way more info/control
Sep 17 21:04:57 <denkenz> But both need to work...
Sep 17 21:06:58 <Jeevaka> ok
**** ENDING LOGGING AT Sat Sep 18 02:59:57 2010