enter pin to zhone

watch frameworkd debug output:

ogsmd    DEBUG    |...|...|...|...|...|...> SimSendAuthCode.__init__: ENTER (<framework.subsystems.ogsmd.objects.Device at /org/freesmartphone/GSM/Device at 0x530310>, <function <lambda> at 0x60ec30>, <function <lambda> at 0x61c6f0>),{'code': dbus.String(u'PIN_XXXX')}
ogsmd    DEBUG    |...|...|...|...|...|...> SimSendAuthCode.__init__: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: last communication with modem was 23 seconds ago. Sending EOF to wakeup)
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([(u'AT+CPIN="PIN_XXXX"\r\n', <bound method SimSendAuthCode.responseFromChannel of <ogsmd.modems.abstract.mediator.SimSendAuthCode object at 0x5d6410>>, <bound method SimSendAuthCode.errorFromChannel of <ogsmd.modems.abstract.mediator.SimSendAuthCode object at 0x5d6410>>, 7)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 20 bytes to /dev/pts/0: u'AT+CPIN="PIN_XXXX"\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 6 bytes from /dev/pts/0: '\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CPIN="PIN_XXXX"' => ['OK'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> SimSendAuthCode.responseFromChannel: ENTER (u'AT+CPIN="PIN_XXXX"', ['OK']),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> SimSendAuthCode.responseFromChannel: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> SimSendAuthCode.__del__: ENTER (),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> SimSendAuthCode.__del__: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([]))(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: nothing in request queue)
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...> DeviceSetAntennaPower.__init__: ENTER (<framework.subsystems.ogsmd.objects.Device at /org/freesmartphone/GSM/Device at 0x530310>, <function <lambda> at 0x60ec30>, <function <lambda> at 0x61c6f0>),{'power': dbus.Boolean(True)}
ogsmd    DEBUG    |...|...|...|...|...|...> DeviceSetAntennaPower.__init__: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+CPIN?\r\n', <bound method DeviceSetAntennaPower.intermediateResponse of <ogsmd.modems.abstract.mediator.DeviceSetAntennaPower object at 0x5d6930>>, <bound method DeviceSetAntennaPower.errorFromChannel of <ogsmd.modems.abstract.mediator.DeviceSetAntennaPower object at 0x5d6930>>, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 10 bytes to /dev/pts/0: 'AT+CPIN?\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 22 bytes from /dev/pts/0: '\r\n+CPIN: READY\r\n\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CPIN?' => ['+CPIN: READY', 'OK'])ogsmd    INFO     auth status changed to READY
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+CFUN=1\r\n', <bound method DeviceSetAntennaPower.responseFromChannel of <ogsmd.modems.abstract.mediator.DeviceSetAntennaPower object at 0x5d6930>>, <bound method DeviceSetAntennaPower.errorFromChannel of <ogsmd.modems.abstract.mediator.DeviceSetAntennaPower object at 0x5d6930>>, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 11 bytes to /dev/pts/0: 'AT+CFUN=1\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 6 bytes from /dev/pts/0: '\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CFUN=1' => ['OK'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> DeviceSetAntennaPower.responseFromChannel: ENTER ('AT+CFUN=1', ['OK']),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> DeviceSetAntennaPower.responseFromChannel: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+CPIN?\r\n', <bound method DeviceSetAntennaPower.intermediateResponse2 of <ogsmd.modems.abstract.mediator.DeviceSetAntennaPower object at 0x5d6930>>, <bound method DeviceSetAntennaPower.errorFromChannel of <ogsmd.modems.abstract.mediator.DeviceSetAntennaPower object at 0x5d6930>>, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 10 bytes to /dev/pts/0: 'AT+CPIN?\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...> NetworkRegister.__init__: ENTER (<framework.subsystems.ogsmd.objects.Device at /org/freesmartphone/GSM/Device at 0x530310>, <function <lambda> at 0x679770>, <function <lambda> at 0x679730>),{}
ogsmd    DEBUG    |...|...|...|...|...|...> NetworkRegister.__init__: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 22 bytes from /dev/pts/0: '\r\n+CPIN: READY\r\n\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CPIN?' => ['+CPIN: READY', 'OK'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> DeviceSetAntennaPower.__del__: ENTER (),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> DeviceSetAntennaPower.__del__: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+COPS=0,0\r\n', <bound method NetworkRegister.responseFromChannel of <ogsmd.modems.abstract.mediator.NetworkRegister object at 0x66a550>>, <bound method NetworkRegister.errorFromChannel of <ogsmd.modems.abstract.mediator.NetworkRegister object at 0x66a550>>, 15)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 13 bytes to /dev/pts/0: 'AT+COPS=0,0\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 12 bytes from /dev/pts/1: '\r\n+CREG: 2\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['+CREG: 2'],),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> UnsolicitedResponseDelegate.plusCREG: ENTER ('2',),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.__init__: ENTER (<framework.subsystems.ogsmd.objects.Device at /org/freesmartphone/GSM/Device at 0x530310>, <bound method UnsolicitedResponseDelegate.statusOK of <framework.subsystems.ogsmd.modems.ti_calypso.unsolicited.UnsolicitedResponseDelegate object at 0x5d6910>>, <bound method UnsolicitedResponseDelegate.statusERR of <framework.subsystems.ogsmd.modems.ti_calypso.unsolicited.UnsolicitedResponseDelegate object at 0x5d6910>>),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.__init__: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> UnsolicitedResponseDelegate.plusCREG: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVEframeworkd.controller DEBUG    alive and kicking
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 16 bytes from /dev/pts/1: '%CSTAT: PHB, 0\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['%CSTAT: PHB, 0'],),{}ogsmd.modem.unsolicited INFO     subsystem PHB readyness now Falseogsmd    INFO     sim ready status Falseogsmd.modem.unsolicited INFO     full readyness now False
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 16 bytes from /dev/pts/1: '%CSTAT: PHB, 0\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['%CSTAT: PHB, 0'],),{}ogsmd.modem.unsolicited INFO     subsystem PHB readyness now Falseogsmd.modem.unsolicited INFO     full readyness now False
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVE
ogsmd    DEBUG    |...|...|...|...> UnsolicitedResponseChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710> queue is: deque([('AT+CNMI=2,1,2,1,1\r\n', None, None, 5), ('AT%CBHZ=1\r\n', None, None, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: sending 19 bytes to /dev/pts/1: 'AT+CNMI=2,1,2,1,1\r\n')
ogsmd    DEBUG    |...|...|...|...> UnsolicitedResponseChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 19 bytes from /dev/pts/1: '\r\n+CMS ERROR: 314\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: COMPLETED 'AT+CNMI=2,1,2,1,1' => ['+CMS ERROR: 314'])
ogsmd    DEBUG    |...|...|...|...> UnsolicitedResponseChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710> queue is: deque([('AT%CBHZ=1\r\n', None, None, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: sending 11 bytes to /dev/pts/1: 'AT%CBHZ=1\r\n')
ogsmd    DEBUG    |...|...|...|...> UnsolicitedResponseChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 19 bytes from /dev/pts/1: '\r\n+CMS ERROR: 314\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: COMPLETED 'AT%CBHZ=1' => ['+CMS ERROR: 314'])
ogsmd    DEBUG    |...|...|...|...> UnsolicitedResponseChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710> queue is: deque([]))(<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: nothing in request queue)
ogsmd    DEBUG    |...|...|...|...> UnsolicitedResponseChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 16 bytes from /dev/pts/1: '%CSTAT: PHB, 0\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['%CSTAT: PHB, 0'],),{}ogsmd.modem.unsolicited INFO     subsystem PHB readyness now Falseogsmd.modem.unsolicited INFO     full readyness now False
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 20 bytes from /dev/pts/1: '\r\n%CSQ:  20, 99, 2\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['%CSQ:  20, 99, 2'],),{}ogsmd    INFO     org.freesmartphone.GSM.Network.SignalStrength: 87
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 17 bytes from /dev/pts/1: '%CSTAT: EONS, 0\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['%CSTAT: EONS, 0'],),{}ogsmd.modem.unsolicited INFO     full readyness now False
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 32 bytes from /dev/pts/1: '%CSTAT: PHB, 0\r\n%CSTAT: SMS, 1\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['%CSTAT: PHB, 0'],),{}ogsmd.modem.unsolicited INFO     subsystem PHB readyness now Falseogsmd.modem.unsolicited INFO     full readyness now False
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['%CSTAT: SMS, 1'],),{}ogsmd.modem.unsolicited INFO     subsystem SMS readyness now Trueogsmd.modem.unsolicited INFO     full readyness now False
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVEodeviced.idlenotifier INFO     framework.subsystems.odeviced.idlenotifier state change to IDLE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 6 bytes from /dev/pts/0: '\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+COPS=0,0' => ['OK'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> NetworkRegister.responseFromChannel: ENTER ('AT+COPS=0,0', ['OK']),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> NetworkRegister.responseFromChannel: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> NetworkRegister.__del__: ENTER (),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> NetworkRegister.__del__: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 26 bytes from /dev/pts/1: '\r\n+CREG: 1,"23A0","9FBF"\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['+CREG: 1,"23A0","9FBF"'],),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> UnsolicitedResponseDelegate.plusCREG: ENTER ('1,"23A0","9FBF"',),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.__init__: ENTER (<framework.subsystems.ogsmd.objects.Device at /org/freesmartphone/GSM/Device at 0x530310>, <bound method UnsolicitedResponseDelegate.statusOK of <framework.subsystems.ogsmd.modems.ti_calypso.unsolicited.UnsolicitedResponseDelegate object at 0x5d6910>>, <bound method UnsolicitedResponseDelegate.statusERR of <framework.subsystems.ogsmd.modems.ti_calypso.unsolicited.UnsolicitedResponseDelegate object at 0x5d6910>>),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.__init__: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> UnsolicitedResponseDelegate.plusCREG: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+CSQ\r\n', <bound method NetworkGetStatus.genResponseFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a750>>, <bound method NetworkGetStatus.genErrorFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a750>>, 5), ('AT+CSQ\r\n', <bound method NetworkGetStatus.genResponseFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a350>>, <bound method NetworkGetStatus.genErrorFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a350>>, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 8 bytes to /dev/pts/0: 'AT+CSQ\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 16 bytes from /dev/pts/0: '\r\n+CSQ: 20,99 \r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 6 bytes from /dev/pts/0: '\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CSQ' => ['+CSQ: 20,99 ', 'OK'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.genResponseFromChannel: ENTER ('AT+CSQ', ['+CSQ: 20,99 ', 'OK']),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.genResponseFromChannel: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+CSQ\r\n', <bound method NetworkGetStatus.genResponseFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a350>>, <bound method NetworkGetStatus.genErrorFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a350>>, 5), ('AT+CREG?;+COPS?\r\n', <bound method NetworkGetStatus.genResponseFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a750>>, <bound method NetworkGetStatus.genErrorFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a750>>, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 8 bytes to /dev/pts/0: 'AT+CSQ\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 22 bytes from /dev/pts/0: '\r\n+CSQ: 20,99 \r\n\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CSQ' => ['+CSQ: 20,99 ', 'OK'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.genResponseFromChannel: ENTER ('AT+CSQ', ['+CSQ: 20,99 ', 'OK']),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.genResponseFromChannel: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+CREG?;+COPS?\r\n', <bound method NetworkGetStatus.genResponseFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a750>>, <bound method NetworkGetStatus.genErrorFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a750>>, 5), ('AT+CREG?;+COPS?\r\n', <bound method NetworkGetStatus.genResponseFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a350>>, <bound method NetworkGetStatus.genErrorFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a350>>, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 17 bytes to /dev/pts/0: 'AT+CREG?;+COPS?\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 14 bytes from /dev/pts/0: '\r\n+CREG: 0,1\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 31 bytes from /dev/pts/0: '\r\n+COPS: 0,0,"FI elisa"\r\n\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CREG?;+COPS?' => ['+CREG: 0,1', '+COPS: 0,0,"FI elisa"', 'OK'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.genResponseFromChannel: ENTER ('AT+CREG?;+COPS?', ['+CREG: 0,1', '+COPS: 0,0,"FI elisa"', 'OK']),{}ogsmd    INFO     org.freesmartphone.GSM.Network.Status: {'strength': 87, 'cid': '9FBF', 'registration': 'home', 'lac': '23A0', 'mode': 'automatic', 'provider': 'FI elisa'}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.genResponseFromChannel: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> NetworkGetStatus.__del__: ENTER (),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> NetworkGetStatus.__del__: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+CREG?;+COPS?\r\n', <bound method NetworkGetStatus.genResponseFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a350>>, <bound method NetworkGetStatus.genErrorFromChannel of <ogsmd.modems.abstract.mediator.NetworkGetStatus object at 0x66a350>>, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 17 bytes to /dev/pts/0: 'AT+CREG?;+COPS?\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 14 bytes from /dev/pts/0: '\r\n+CREG: 0,1\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 31 bytes from /dev/pts/0: '\r\n+COPS: 0,0,"FI elisa"\r\n\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CREG?;+COPS?' => ['+CREG: 0,1', '+COPS: 0,0,"FI elisa"', 'OK'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.genResponseFromChannel: ENTER ('AT+CREG?;+COPS?', ['+CREG: 0,1', '+COPS: 0,0,"FI elisa"', 'OK']),{}ogsmd    INFO     org.freesmartphone.GSM.Network.Status: {'strength': 87, 'cid': '9FBF', 'registration': 'home', 'lac': '23A0', 'mode': 'automatic', 'provider': 'FI elisa'}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> NetworkGetStatus.genResponseFromChannel: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> NetworkGetStatus.__del__: ENTER (),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> NetworkGetStatus.__del__: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([]))(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: nothing in request queue)
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 20 bytes from /dev/pts/1: '\r\n%CSQ:  16, 99, 1\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['%CSQ:  16, 99, 1'],),{}ogsmd    INFO     org.freesmartphone.GSM.Network.SignalStrength: 81
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 20 bytes from /dev/pts/1: '\r\n%CSQ:  20, 99, 2\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['%CSQ:  20, 99, 2'],),{}ogsmd    INFO     org.freesmartphone.GSM.Network.SignalStrength: 87
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.UnsolicitedResponseChannel object at 0x5d6710>: got 16 bytes from /dev/pts/1: '%CSTAT: PHB, 1\r\n')
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: ENTER (['%CSTAT: PHB, 1'],),{}ogsmd.modem.unsolicited INFO     subsystem PHB readyness now Trueogsmd    INFO     sim ready status Trueogsmd.modem.unsolicited INFO     full readyness now True
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> UnsolicitedResponseChannel._handleUnsolicitedResponse: LEAVEodeviced.idlenotifier INFO     framework.subsystems.odeviced.idlenotifier state change to IDLE_DIM
ogsmd    DEBUG    |...|...|...|...|...|...> SimRetrievePhonebook.__init__: ENTER (<framework.subsystems.ogsmd.objects.Device at /org/freesmartphone/GSM/Device at 0x530310>, <function <lambda> at 0x679770>, <function <lambda> at 0x679730>),{}
ogsmd    DEBUG    |...|...|...|...|...|...> SimRetrievePhonebook.__init__: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...> SimGetPhonebookInfo.__init__: ENTER (<framework.subsystems.ogsmd.objects.Device at /org/freesmartphone/GSM/Device at 0x530310>, <bound method SimRetrievePhonebook.tryAgain of <ogsmd.modems.abstract.mediator.SimRetrievePhonebook object at 0x66a810>>, <bound method SimRetrievePhonebook.reportError of <ogsmd.modems.abstract.mediator.SimRetrievePhonebook object at 0x66a810>>),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...> SimGetPhonebookInfo.__init__: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...> SimRetrieveMessagebook.__init__: ENTER (<framework.subsystems.ogsmd.objects.Device at /org/freesmartphone/GSM/Device at 0x530310>, <function <lambda> at 0x679cf0>, <function <lambda> at 0x679cb0>),{'category': dbus.String(u'all')}
ogsmd    DEBUG    |...|...|...|...|...|...> SimRetrieveMessagebook.__init__: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+CPBS="SM";+CPBR=?\r\n', <bound method SimGetPhonebookInfo.responseFromChannel of <ogsmd.modems.abstract.mediator.SimGetPhonebookInfo object at 0x66a550>>, <bound method SimGetPhonebookInfo.errorFromChannel of <ogsmd.modems.abstract.mediator.SimGetPhonebookInfo object at 0x66a550>>, 5), ('AT+CMGL="ALL"\r\n', <bound method SimRetrieveMessagebook.responseFromChannel of <ogsmd.modems.abstract.mediator.SimRetrieveMessagebook object at 0x66a7b0>>, <bound method SimRetrieveMessagebook.errorFromChannel of <ogsmd.modems.abstract.mediator.SimRetrieveMessagebook object at 0x66a7b0>>, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 22 bytes to /dev/pts/0: 'AT+CPBS="SM";+CPBR=?\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 30 bytes from /dev/pts/0: '\r\n+CPBR: (1-250),44,20\r\n\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CPBS="SM";+CPBR=?' => ['+CPBR: (1-250),44,20', 'OK'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> SimGetPhonebookInfo.__del__: ENTER (),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> SimGetPhonebookInfo.__del__: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+CMGL="ALL"\r\n', <bound method SimRetrieveMessagebook.responseFromChannel of <ogsmd.modems.abstract.mediator.SimRetrieveMessagebook object at 0x66a7b0>>, <bound method SimRetrieveMessagebook.errorFromChannel of <ogsmd.modems.abstract.mediator.SimRetrieveMessagebook object at 0x66a7b0>>, 5), ('AT+CPBS="SM";+CPBR=1,250\r\n', <bound method SimRetrievePhonebook.responseFromChannel of <ogsmd.modems.abstract.mediator.SimRetrievePhonebook object at 0x66a810>>, <bound method SimRetrievePhonebook.errorFromChannel of <ogsmd.modems.abstract.mediator.SimRetrievePhonebook object at 0x66a810>>, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 15 bytes to /dev/pts/0: 'AT+CMGL="ALL"\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 19 bytes from /dev/pts/0: '\r\n+CMS ERROR: 321\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CMGL="ALL"' => ['+CMS ERROR: 321'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> SimRetrieveMessagebook.responseFromChannel: ENTER ('AT+CMGL="ALL"', ['+CMS ERROR: 321']),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...|...|...> SimRetrieveMessagebook.responseFromChannel: ENTER ('AT+CMGL="ALL"', ['+CMS ERROR: 321']),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...|...|...|...|...> SimRetrieveMessagebook._handleCmeCmsExtError: ENTER ('+CMS ERROR: 321',),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...|...|...|...|...> SimRetrieveMessagebook._handleCmeCmsExtError: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...|...|...> SimRetrieveMessagebook.responseFromChannel: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> SimRetrieveMessagebook.responseFromChannel: LEAVE
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> SimRetrieveMessagebook.__del__: ENTER (),{}
ogsmd    DEBUG    |...|...|...|...|...|...|...|...> SimRetrieveMessagebook.__del__: LEAVE
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: ENTER (),{}(<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850> queue is: deque([('AT+CPBS="SM";+CPBR=1,250\r\n', <bound method SimRetrievePhonebook.responseFromChannel of <ogsmd.modems.abstract.mediator.SimRetrievePhonebook object at 0x66a810>>, <bound method SimRetrievePhonebook.errorFromChannel of <ogsmd.modems.abstract.mediator.SimRetrievePhonebook object at 0x66a810>>, 5)]))
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: sending 26 bytes to /dev/pts/0: 'AT+CPBS="SM";+CPBR=1,250\r\n')
ogsmd    DEBUG    |...|...|...|...> MiscChannel.readyToSend: LEAVE
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 44 bytes from /dev/pts/0: '\r\n+CPBR: 50,"35880095050",145,"Radiolinja"\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 48 bytes from /dev/pts/0: '+CPBR: 51,"3585090599",145,"Saldotietopalvelu"\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: got 38 bytes from /dev/pts/0: '+CPBR: 52,"777",177,"Vastaaja"\r\n\r\nOK\r\n')
ogsmd    DEBUG    (<framework.subsystems.ogsmd.modems.ti_calypso.channel.MiscChannel object at 0x5d6850>: COMPLETED 'AT+CPBS="SM";+CPBR=1,250' => ['+CPBR: 50,"35880095050",145,"Radiolinja"', '+CPBR: 51,"3585090599",145,"Saldotietopalvelu"', '+CPBR: 52,"777",177,"Vastaaja"', 'OK'])
ogsmd    DEBUG    |...|...|...|...|...|...|...|...|...|...> SimRetrievePhonebook.responseFromChannel: ENTER ('AT+CPBS="SM";+CPBR=1,250', ['+CPBR: 50,"35880095050",145,"Radiolinja"', '+CPBR: 51,"3585090599",145,"Saldotietopalvelu"', '+CPBR: 52,"777",177,"Vastaaja"', 'OK']),{}
Traceback (most recent call last):
  File "/var/lib/python-support/python2.5/framework/subsystems/ogsmd/gsm/channel.py", line 218, in _readyToRead
    self.readyToRead( data )
  File "/var/lib/python-support/python2.5/framework/subsystems/ogsmd/gsm/channel.py", line 354, in readyToRead
    self.parser.feed( data, not self.q.empty() )
  File "/var/lib/python-support/python2.5/framework/subsystems/ogsmd/gsm/parser.py", line 127, in feed
    nextstate = self.state( b, haveCommand )
  File "/var/lib/python-support/python2.5/framework/subsystems/ogsmd/gsm/parser.py", line 175, in state_inline_r
    return self.solicitedLineCompleted()
  File "/var/lib/python-support/python2.5/framework/subsystems/ogsmd/gsm/parser.py", line 204, in solicitedLineCompleted
    self.response( self.lines )
  File "/var/lib/python-support/python2.5/framework/subsystems/ogsmd/gsm/channel.py", line 443, in _handleResponseToRequest
    self.handleResponseToRequest( request, response )
  File "/var/lib/python-support/python2.5/framework/subsystems/ogsmd/gsm/channel.py", line 382, in handleResponseToRequest
    ok_cb( reqstring.strip(), response )
  File "/var/lib/python-support/python2.5/framework/subsystems/ogsmd/gsm/decor.py", line 45, in logIt
    result = fn( *args, **kwargs )
  File "/var/lib/python-support/python2.5/framework/subsystems/ogsmd/modems/abstract/mediator.py", line 566, in responseFromChannel
    result.append( ( index, name, const.phonebookTupleToNumber( number, ntype ) ) )
  File "/var/lib/python-support/python2.5/framework/subsystems/ogsmd/gsm/const.py", line 805, in phonebookTupleToNumber
    assert ntype in ( 129, 145, 208 ), "unknown type %i" % ntype
AssertionError: unknown type 177
odeviced.idlenotifier INFO     framework.subsystems.odeviced.idlenotifier state change to IDLE_PRELOCK