Can't register with GSM network

[dkogan@…]

Hi all. I'm running the latest SHR snapshot (11/25/2008) on a Freerunner with moko10_beta2 GSM firmware. SHR can not register with the network, and neither can Zhone from the latest FSO milestone. Qtopia seems to be able to, though. Very rarely I CAN register, but most of the time SHR just says "Searching...." The FSO log with DEBUG enabled is at

http://secretsauce.net:5050/fso.log

It seems like the phone isn't seeing a signal, but I really don't know much at the AT commands of the calypso to be sure. Let me know how I can help debug this.

[dkogan]

I just spent a bit of time studying the logs from Qtopia (registers with network) and FSO (fails to register with network). It seems like the magic command that makes Qtopia work is

AT+COPS=0

All COPS* commands in FSO are AT+COPS=3,0. This seems to be insufficient with my carrier+SIM. Studying this a bit further, I'm seeing reliable network registration if I run

ATE0 AT+CREG=2 AT+CGREG=2 AT+CFUN=1 AT+COPS=3,0 AT+COPS=0

If I do the same, but leave out the last line, the phone never registers. These two cases are analogous to what Qtopia and FSO currently do. Do I need to do anything else to help fix this?

[dkogan]

I've possibly figured it out. For whatever reason, when I do see registrations, it takes 110s (this is very consistent). This is greater than the 30s timeout in FSO. Raising this timeout improves matters, but I still see times when it doesn't register. If I figure out how to make it fail consistently, I'll post a new log.

[dkogan]

I just tried again with a brand new copy of FSO from git (new as of Dec. 11). FSO consistently refuses to register. I'm attaching a log showing this. One thing I did notice is that when I register by manually issuing commands to the modem, it succeeds with code 5 (roaming), and never with code 1 (home network). There's no reason for it to be roaming here, and when I tried with a different SIM card, it registered after 4 seconds with code 1. Interestingly, both SIM cards register with the same tower (same carrier, same reported cell ID).

[dkogan]

FSO refuses to register to the network

[mickey]

This looks like it's a very slow SIM card. We might need to increase timeouts here.

However, I can't find a failure in "fso.broken.log". In line 971, we issue +COPS=0,0 to register, but before this can ever complete, the GSM subsystem gets shutdown in line 997.

Illume constantly trying to get signal strength is pretty much polluting the logs -- can you retry without running the GSM gadget (or the window manager)?

[dkogan]

Thanks for replying, Mickey. I just made a log without the gadget running, and it does seem like GSM is shutting down before the phone registers. I did increase the COPS timeout in /usr/lib/python2.5/site-packages/framework/subsystems/ogsmd/modems/abstract/modem.py:

self._timeouts = { \

"SIMAUTH": 15, "SIMACCESS": 10, "NETWORK": 10, "CFUN": 10, "COPS": 230, "COPS=?": 80, "RING": 04, }

It seems to me like the phone is trying to go to sleep, and none of these timeouts is what's affecting it. I'm attaching the new log.

[dkogan]

FSO log with the GSM gadget disabled

[mickey]

Ok, it's definitely something external to FSO disabling the GSM subsystem -- perhaps something bogus in the SHR rules file (they're not using the FSO default one) or "just" crashing.

To make sure it's not FSO at fault, I'd advise shutting down everything that uses FSO and trying to register on your own. Use cli-framework to do that.

[dkogan]

I just ran a registration cycle with cli-framework. I started frameworkd, then ran

usageiface.RequestResource('GSM')
gsmdevice.SetAntennaPower(1)
gsmnetwork.Register()

The Register() call did not return for a while, and finally threw an exception:

>>> gsmnetwork.Register()
Traceback (most recent call last):
  File "<console>", line 1, in <module>
  File "/usr/lib/python2.5/site-packages/dbus/proxies.py", line 68, in __call__
    return self._proxy_method(*args, **keywords)
  File "/usr/lib/python2.5/site-packages/dbus/proxies.py", line 140, in __call__
    **keywords)
  File "/usr/lib/python2.5/site-packages/dbus/connection.py", line 622, in call_blocking
    message, timeout)
DBusException: org.freesmartphone.GSM.Network.Unauthorized: 

The phone did eventually register, though. I'm including the log. Something potentially interesting is that the exception is thrown 60 seconds after the Register() command, while the registration occurred 94 seconds after. So do you still think this issue is external to FSO? Can you be more specific as to which SHR rules file you think may be causing this? Should I post to the SHR bug tracker? Thanks.

[dkogan]

FSO log made with cli-framework only

[dkogan]

It seems that adding

[odeviced.idlenotifier]
suspend = 0

to frameworkd.conf resolves this issue. This makes some sense since we see the following in the nogadget log right before the GSM is turned off erroneously:

2008.12.10 21:16:07 odeviced.idlenotifier INFO     odeviced.idlenotifier state change to suspend
2008.12.10 21:16:07 odeviced.idlenotifier DEBUG    Timeout for awake disabled, not falling into this state next.
2008.12.10 21:16:07 oeventsd DEBUG    trigger DBusTrigger(org.freesmartphone.odeviced None.State)
2008.12.10 21:16:07 oeventsd DEBUG    trigger on DBusTrigger(org.freesmartphone.odeviced None.State) if And() then Debug("dbus trigger test")
2008.12.10 21:16:07 oeventsd INFO     DebugAction : dbus trigger test
2008.12.10 21:16:07 oeventsd INFO     Receive IdleState, status = suspend
2008.12.10 21:16:07 oeventsd DEBUG    trigger IdleState
2008.12.10 21:16:07 oeventsd INFO     Receive IdleState, status = suspend
2008.12.10 21:16:07 oeventsd DEBUG    trigger IdleState
2008.12.10 21:16:07 oeventsd INFO     Receive IdleState, status = suspend
2008.12.10 21:16:07 oeventsd DEBUG    trigger IdleState
2008.12.10 21:16:07 ousaged  DEBUG    Disabling GSM

It would look like the idlenotifier is causing the suspend. However, in the cli log we see this:

2008.12.10 21:58:06 odeviced.idlenotifier INFO     odeviced.idlenotifier state change to suspend
2008.12.10 21:58:06 odeviced.idlenotifier DEBUG    Timeout for awake disabled, not falling into this state next.
2008.12.10 21:58:06 oeventsd DEBUG    trigger DBusTrigger(org.freesmartphone.odeviced None.State)
2008.12.10 21:58:06 oeventsd DEBUG    trigger on DBusTrigger(org.freesmartphone.odeviced None.State) if And() then Debug("dbus trigger test")
2008.12.10 21:58:06 oeventsd INFO     DebugAction : dbus trigger test
2008.12.10 21:58:06 oeventsd INFO     Receive IdleState, status = suspend
2008.12.10 21:58:06 oeventsd DEBUG    trigger IdleState
2008.12.10 21:58:06 oeventsd INFO     Receive IdleState, status = suspend
2008.12.10 21:58:06 oeventsd DEBUG    trigger IdleState
2008.12.10 21:58:06 oeventsd INFO     Receive IdleState, status = suspend
2008.12.10 21:58:06 oeventsd DEBUG    trigger IdleState

This is essentially the same sequence, except it doesn't end with the GSM system shutting down, and in THIS case the phone did register successfully. Ideas? What is disabling the GSM?

[mickey]

Can you retry with latest SHR and/or FSO ms5?

[dkogan]

This issue turned out to be tickled by the particular SIM card that I was using. I have since switched to a different SIM card. The new SIM registers quickly, before the Freerunner GSM would shut down. I thus can't reproduce the error anymore. It was a very old SIM, and I've never seen another exhibit the slow behavior, so maybe it's OK to close this? Thanks.

[mickey]

Ah I see. Yes, lets close it then. Feel free to reopen, if it happens again.