Skip to content

Instantly share code, notes, and snippets.

@thkoch2001
Created March 7, 2012 10:15
Show Gist options
  • Save thkoch2001/1992379 to your computer and use it in GitHub Desktop.
Save thkoch2001/1992379 to your computer and use it in GitHub Desktop.
wader support for ericsson_f5521gw
2012-03-07 11:10:14+0100 [-] Log opened.
2012-03-07 11:10:14+0100 [-] twistd 11.1.0 (/usr/bin/python 2.7.2) starting up.
2012-03-07 11:10:14+0100 [-] reactor class: twisted.internet.glib2reactor.Glib2Reactor.
2012-03-07 11:10:14+0100 [-] get_plugin_by_id called with 0xBDB and 0x1911
2012-03-07 11:10:14+0100 [-] registering plugin <EricssonF3607gw dport: /dev/ttyACM0 cport: /dev/ttyACM1> with opath /org/freedesktop/ModemManager/Devices/0
2012-03-07 11:10:14+0100 [-] wrapping plugin <EricssonF3607gw dport: /dev/ttyACM0 cport: /dev/ttyACM1> with class <class 'core.hardware.ericsson.EricssonF3607gwWrapper'>
2012-03-07 11:10:14+0100 [-] exporting <EricssonF3607gw dport: /dev/ttyACM0 cport: /dev/ttyACM1> methods with class <class 'core.exported.WCDMAExporter'>
2012-03-07 11:10:14+0100 [-] emitting DeviceAdded('/org/freedesktop/ModemManager/Devices/0')
2012-03-07 11:10:19+0100 [-] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem {'Enabled': dbus.Boolean(False)}
2012-03-07 11:10:19+0100 [-] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem {'State': dbus.UInt32(30L)}
2012-03-07 11:10:19+0100 [-] emitting StateChanged(10, 30, 0)
2012-03-07 11:10:19+0100 [ttyACM1] idle: '\r\n*EMRDY: 1\r\n'
2012-03-07 11:10:19+0100 [ttyACM1] idle: unmatched data '\r\n*EMRDY: 1\r\n'
2012-03-07 11:10:20+0100 [-] starting AuthStateMachine ...
2012-03-07 11:10:20+0100 [-] authentication_sm: transition to get_pin_status mode....
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CPIN?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data 'AT+CPIN?\r'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CPIN: READY\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('READY',)]
2012-03-07 11:10:20+0100 [ttyACM1] Enabling radio and initialising SIM
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CFUN?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data 'AT+CFUN?\r'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CFUN: 5\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT&F'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data 'AT&F\r'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'ATE0'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data 'ATE0\r'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CPBS="SM"'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CMEE=1'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CSCS=?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CSCS: ('
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '"GSM","IRA","8859-1","UTF-8","UCS2")\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('GSM',), ('IRA',), ('8859-1',), ('UTF-8',), ('UCS2',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CNMI=2,1,0,1,0'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CMGF=0'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CPBR=?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CPBR: (1-200),420,18,18,420,128\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('200', ',420,18,18,420,128')]
2012-03-07 11:10:20+0100 [ttyACM1] Setting size to 200
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CSCS?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CSCS: "'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data 'IRA"\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('IRA',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CPMS="SM","SM","SM"'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CPMS: 7,20,7,20,7,20\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CSCS="UCS2"'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CMER=3,0,0,1'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:20+0100 [ttyACM1] daemon SignalQualityDaemon started...
2012-03-07 11:10:20+0100 [ttyACM1] executing SignalQualityDaemon.function every 15 seconds
2012-03-07 11:10:20+0100 [ttyACM1] daemon NetworkRegistrationDaemon started...
2012-03-07 11:10:20+0100 [ttyACM1] executing NetworkRegistrationDaemon.function every 120 seconds
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem {'UnlockRetries': 999}
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Ussd {'State': 'idle'}
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Card {'SupportedBands': dbus.UInt32(0L)}
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Card {'SupportedModes': dbus.UInt32(384L)}
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:10:20+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CREG?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CREG: 0,5\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('0', '5', None)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CLCK="00530043",2'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CLCK: 1\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('1',)]
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Card {'PinEnabled': True}
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+COPS=3,2;+COPS?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+COPS: 0,2,"00320032003800300031",0 \r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('0,2,"00320032003800300031",0', None, '00320032003800300031', '0')]
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Network {'AccessTechnology': dbus.UInt32(3L)}
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CGSN'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n356403043379128\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('356403043379128',)]
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem {'EquipmentIdentifier': '356403043379128'}
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+COPS=3,0;+COPS?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+COPS: 0,0,"005300770069007300730063006F006D",0 \r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('0,0,"005300770069007300730063006F006D",0', None, '005300770069007300730063006F006D', '0')]
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Network {'AccessTechnology': dbus.UInt32(3L)}
2012-03-07 11:10:20+0100 [ttyACM1] emitting DeviceEnabled('/org/freedesktop/ModemManager/Devices/0')
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem {'Enabled': dbus.Boolean(True)}
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem {'State': dbus.UInt32(60L)}
2012-03-07 11:10:20+0100 [ttyACM1] emitting StateChanged(30, 60, 0)
2012-03-07 11:10:20+0100 [ttyACM1] emitting RegistrationInfo(5, '22801', 'Swisscom')
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CRSM=176,12258,0,0,10'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [-] middleware::get_netreg_info served from cache
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CRSM: 144,0,"00390038003900340030003200300033003100350035003000370033003400360033003900330037"\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('144', '0', '00390038003900340030003200300033003100350035003000370033003400360033003900330037')]
2012-03-07 11:10:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Card {'SimIdentifier': u'89492030510537649373'}
2012-03-07 11:10:20+0100 [ttyACM1] MAL::initialize obj: F5521gw
2012-03-07 11:10:20+0100 [ttyACM1] MAL::list_sms
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CMGL=4'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CMGL: 1,1,,139\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '07911497949900F0040B911497674955F400001170223133758089CD72DA5D0689DF73777A3E469741CE7ABB5D96EB40AB19EE06B2D568B29A0D0703B55A2062BA0C9A269BAD65584E2F83D2733AC85D7783D26D90F65E4ED3D1E1B29B9C768188E93228289E97DDE4B2DC5D6FB7CB72507A4E07B5CB6937683A46DFCB697D590E4286CB6E72DA053ACAEBF3390B14C497D92E\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '+CMGL: 2,1,,142\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '0791947122723033200481550042001101719015118091D637396C7EBBCB8A6638CD16BFF10A67B95E0639C363744B214F8FD1F4B23BA498C2E5E131BAAC8B298C61BC0EA688CD5E31D82B1653C0723A5A4E215AD172B7DA2C96CBD562B2184CA4202A414137FD9D76974F7310324D0785D97390515E4EEBCBE931BAECA6BFDD3F90E2280FD3D373904C56C3C14061B7BC6E2EBB430A\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '+CMGL: 3,1,,159\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '0791947101670000240C919471535196440000211072712224409FC834888E7EB7C373567A8C0689D36ED0995D4E8FD120F77B8C06D5DDF4B2FC5E3ECF5DEBB0DB3DA783C875503B2D0789CBF331BA9C2683E6E173D9CDBA87DD6E10B90E1297D3A0765A0E0ABBD7EF769BCEBA97DD6E10B90E2287E7A0BAFB5C36EFD17250583C1FA3F7747DD90D5A87DDEE399D450EB7D374507A8C0685EB6334881C76BB41E430489C76BB00\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '+CMGL: 4,1,,153\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '0791947122723033200C8110150518031141002130504193414099D637396C7EBBCBA06638CD16BFF13A50710EBAD7E5E432685D4EBBCB2067788C96A7C7683A089D76D3CB7276783E2FBB758A152D17ABC56A305C6C068BC514B0990B3673C96031192846D3CD70BA584C110359CBF2797D8C5634D36374B8CC0651CBECF71C649497D3FA727A8C2EBBE96FF74F719487E9E9394826ABE160A0B05B5E3797DD21\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '+CMGL: 5,1,,154\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '07919471227230330405812219F9FF00213070806063409DCEF4184D07D9CBF273793E2FBB75A01AA85895828A78BA3CDC12BEDDF539C8EC97838EE5395CBE1FA3CBA0B41B1464328B2032DD057296E9FA32689E1EA3CB72770814AB818A5529E858A7A3C3E2B21B244ECF41B0DC0B367BC9603119285C37B3C3E4B21B54779341ECF71C742EA3E9F310088412BEDDF539E8EC67D3D36790D92F07DD40D4F0B99C02\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '+CMGL: 6,1,,156\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '07919471227230336405812122F000F121307080123340A00500030B0201AE69367BFD6EB7CB6E50DA0D2297E5A0E9187D2FA7F52150334D0725D1F2721B647D93C3E6B7BB0C9296D3F3B2B52C9FC3E5E531BAEC06ADDF737AD90D0ABAE5757319E40E8FD12062B94E9F8FD1ECB09B0CAABBC9A0B41B442ECB41D331FA5E4EEB41B21C68487F35D36ED00A74AB8186F457D02DAF9B5DA0A07BFD6EB7CB6E72191474CBEB\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '+CMGL: 7,1,,72\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '07919471227230336405812122F000F1213070801243403F0500030B0202CC65D0FA3DA797DD20717A0ED2D7413618A89976D7E96537E856030DE9AFA05B5E37BB40F7FBDD657F93C3E6B7BBEC229701\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('1', '1', '07911497949900F0040B911497674955F400001170223133758089CD72DA5D0689DF73777A3E469741CE7ABB5D96EB40AB19EE06B2D568B29A0D0703B55A2062BA0C9A269BAD65584E2F83D2733AC85D7783D26D90F65E4ED3D1E1B29B9C768188E93228289E97DDE4B2DC5D6FB7CB72507A4E07B5CB6937683A46DFCB697D590E4286CB6E72DA053ACAEBF3390B14C497D92E'), ('2', '1', '0791947122723033200481550042001101719015118091D637396C7EBBCB8A6638CD16BFF10A67B95E0639C363744B214F8FD1F4B23BA498C2E5E131BAAC8B298C61BC0EA688CD5E31D82B1653C0723A5A4E215AD172B7DA2C96CBD562B2184CA4202A414137FD9D76974F7310324D0785D97390515E4EEBCBE931BAECA6BFDD3F90E2280FD3D373904C56C3C14061B7BC6E2EBB430A'), ('3', '1', '0791947101670000240C919471535196440000211072712224409FC834888E7EB7C373567A8C0689D36ED0995D4E8FD120F77B8C06D5DDF4B2FC5E3ECF5DEBB0DB3DA783C875503B2D0789CBF331BA9C2683E6E173D9CDBA87DD6E10B90E1297D3A0765A0E0ABBD7EF769BCEBA97DD6E10B90E2287E7A0BAFB5C36EFD17250583C1FA3F7747DD90D5A87DDEE399D450EB7D374507A8C0685EB6334881C76BB41E430489C76BB00'), ('4', '1', '0791947122723033200C8110150518031141002130504193414099D637396C7EBBCBA06638CD16BFF13A50710EBAD7E5E432685D4EBBCB2067788C96A7C7683A089D76D3CB7276783E2FBB758A152D17ABC56A305C6C068BC514B0990B3673C96031192846D3CD70BA584C110359CBF2797D8C5634D36374B8CC0651CBECF71C649497D3FA727A8C2EBBE96FF74F719487E9E9394826ABE160A0B05B5E3797DD21'), ('5', '1', '07919471227230330405812219F9FF00213070806063409DCEF4184D07D9CBF273793E2FBB75A01AA85895828A78BA3CDC12BEDDF539C8EC97838EE5395CBE1FA3CBA0B41B1464328B2032DD057296E9FA32689E1EA3CB72770814AB818A5529E858A7A3C3E2B21B244ECF41B0DC0B367BC9603119285C37B3C3E4B21B54779341ECF71C742EA3E9F310088412BEDDF539E8EC67D3D36790D92F07DD40D4F0B99C02'), ('6', '1', '07919471227230336405812122F000F121307080123340A00500030B0201AE69367BFD6EB7CB6E50DA0D2297E5A0E9187D2FA7F52150334D0725D1F2721B647D93C3E6B7BB0C9296D3F3B2B52C9FC3E5E531BAEC06ADDF737AD90D0ABAE5757319E40E8FD12062B94E9F8FD1ECB09B0CAABBC9A0B41B442ECB41D331FA5E4EEB41B21C68487F35D36ED00A74AB8186F457D02DAF9B5DA0A07BFD6EB7CB6E72191474CBEB'), ('7', '1', '07919471227230336405812122F000F1213070801243403F0500030B0202CC65D0FA3DA797DD20717A0ED2D7413618A89976D7E96537E856030DE9AFA05B5E37BB40F7FBDD657F93C3E6B7BBEC229701')]
2012-03-07 11:10:20+0100 [ttyACM1] MAL::list_sms::gen_cache
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms: { 'completed': False,
2012-03-07 11:10:20+0100 [ttyACM1] 'count': None,
2012-03-07 11:10:20+0100 [ttyACM1] 'csca': '+41794999000',
2012-03-07 11:10:20+0100 [ttyACM1] 'datetime': datetime.datetime(2011, 7, 22, 11, 33, 57, tzinfo=<UTC>),
2012-03-07 11:10:20+0100 [ttyACM1] 'fragments': [ ( 0,
2012-03-07 11:10:20+0100 [ttyACM1] u'Meine bosnische Nummer: +387 65425680 -- Die SIM-Karte ist nun im Zweithaendi. Die Absendernummer ist mein Schweizer Haendi. Gruss, Axel.')],
2012-03-07 11:10:20+0100 [ttyACM1] 'index': 1,
2012-03-07 11:10:20+0100 [ttyACM1] 'number': '+41797694554',
2012-03-07 11:10:20+0100 [ttyACM1] 'real_indexes': set(),
2012-03-07 11:10:20+0100 [ttyACM1] 'reference': None,
2012-03-07 11:10:20+0100 [ttyACM1] 'sequence': 0}
2012-03-07 11:10:20+0100 [ttyACM1]
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms single part SMS added with logical index: 1
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms: { 'completed': False,
2012-03-07 11:10:20+0100 [ttyACM1] 'count': None,
2012-03-07 11:10:20+0100 [ttyACM1] 'csca': '+491722270333',
2012-03-07 11:10:20+0100 [ttyACM1] 'datetime': datetime.datetime(2011, 10, 17, 7, 51, 11, tzinfo=<UTC>),
2012-03-07 11:10:20+0100 [ttyACM1] 'fragments': [ ( 0,
2012-03-07 11:10:20+0100 [ttyACM1] u'Vodafone\nMailbox\nNeue Nach-\nrichten!\nSprache:1\nFax:0\n13/10/11\n09:49\n"+4975319951210"\nDJ Antoine\'s Hit als Freizeichenton? \nGratis 22580 anrufen!\n')],
2012-03-07 11:10:20+0100 [ttyACM1] 'index': 2,
2012-03-07 11:10:20+0100 [ttyACM1] 'number': '5500',
2012-03-07 11:10:20+0100 [ttyACM1] 'real_indexes': set(),
2012-03-07 11:10:20+0100 [ttyACM1] 'reference': None,
2012-03-07 11:10:20+0100 [ttyACM1] 'sequence': 0}
2012-03-07 11:10:20+0100 [ttyACM1]
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms single part SMS added with logical index: 2
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms: { 'completed': False,
2012-03-07 11:10:20+0100 [ttyACM1] 'count': None,
2012-03-07 11:10:20+0100 [ttyACM1] 'csca': '+491710760000',
2012-03-07 11:10:20+0100 [ttyACM1] 'datetime': datetime.datetime(2012, 1, 27, 16, 22, 42, tzinfo=<UTC>),
2012-03-07 11:10:20+0100 [ttyACM1] 'fragments': [ ( 0,
2012-03-07 11:10:20+0100 [ttyACM1] u'Hi thomas,ich bin gleich noch unterwegs.kannst du mir bescheid sagen,wann du bei mir ankommt,wenn du das ungef\xe4hr absch\xe4tzen kannst,damit ich auch dann da bin.')],
2012-03-07 11:10:20+0100 [ttyACM1] 'index': 3,
2012-03-07 11:10:20+0100 [ttyACM1] 'number': '+491735156944',
2012-03-07 11:10:20+0100 [ttyACM1] 'real_indexes': set(),
2012-03-07 11:10:20+0100 [ttyACM1] 'reference': None,
2012-03-07 11:10:20+0100 [ttyACM1] 'sequence': 0}
2012-03-07 11:10:20+0100 [ttyACM1]
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms single part SMS added with logical index: 3
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms: { 'completed': False,
2012-03-07 11:10:20+0100 [ttyACM1] 'count': None,
2012-03-07 11:10:20+0100 [ttyACM1] 'csca': '+491722270333',
2012-03-07 11:10:20+0100 [ttyACM1] 'datetime': datetime.datetime(2012, 3, 5, 13, 39, 14, tzinfo=<UTC>),
2012-03-07 11:10:20+0100 [ttyACM1] 'fragments': [ ( 0,
2012-03-07 11:10:20+0100 [ttyACM1] u'Vodafone Mailbox: Es wurde keine Nachricht hinterlassen:\n+4915150813011\n03.03.2012 14:38:11\n1 Versuch\nMichael Telos Freizeichenton?\nGratis 22580 anrufen!')],
2012-03-07 11:10:20+0100 [ttyACM1] 'index': 4,
2012-03-07 11:10:20+0100 [ttyACM1] 'number': '015150813011',
2012-03-07 11:10:20+0100 [ttyACM1] 'real_indexes': set(),
2012-03-07 11:10:20+0100 [ttyACM1] 'reference': None,
2012-03-07 11:10:20+0100 [ttyACM1] 'sequence': 0}
2012-03-07 11:10:20+0100 [ttyACM1]
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms single part SMS added with logical index: 4
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms: { 'completed': False,
2012-03-07 11:10:20+0100 [ttyACM1] 'count': None,
2012-03-07 11:10:20+0100 [ttyACM1] 'csca': '+491722270333',
2012-03-07 11:10:20+0100 [ttyACM1] 'datetime': datetime.datetime(2012, 3, 7, 7, 6, 36, tzinfo=<UTC>),
2012-03-07 11:10:20+0100 [ttyACM1] 'fragments': [ ( 0,
2012-03-07 11:10:20+0100 [ttyACM1] u'Nicht vergessen: 5 EUR Extra-Bonus f\xfcr Gespr\xe4che in ALLE dt. Netze sichern! 15 EUR Guthaben bis 09/03/2012 aufladen und los gehts! (Bonus g\xfcltig f\xfcr 7 Tage)')],
2012-03-07 11:10:20+0100 [ttyACM1] 'index': 5,
2012-03-07 11:10:20+0100 [ttyACM1] 'number': '22919',
2012-03-07 11:10:20+0100 [ttyACM1] 'real_indexes': set(),
2012-03-07 11:10:20+0100 [ttyACM1] 'reference': None,
2012-03-07 11:10:20+0100 [ttyACM1] 'sequence': 0}
2012-03-07 11:10:20+0100 [ttyACM1]
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms single part SMS added with logical index: 5
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms: { 'completed': False,
2012-03-07 11:10:20+0100 [ttyACM1] 'count': 2,
2012-03-07 11:10:20+0100 [ttyACM1] 'csca': '+491722270333',
2012-03-07 11:10:20+0100 [ttyACM1] 'datetime': datetime.datetime(2012, 3, 7, 7, 21, 33, tzinfo=<UTC>),
2012-03-07 11:10:20+0100 [ttyACM1] 'fragments': [ ( 1,
2012-03-07 11:10:20+0100 [ttyACM1] u'Willkommen in der Schweiz! Mit Ihrem Vodafone ReiseVersprechen kosten Anrufe nach Deutschland und in der Schweiz 29 Ct/Min + 75 Ct/Anruf. Ankommende Anru')],
2012-03-07 11:10:20+0100 [ttyACM1] 'index': 6,
2012-03-07 11:10:20+0100 [ttyACM1] 'number': '12220',
2012-03-07 11:10:20+0100 [ttyACM1] 'real_indexes': set(),
2012-03-07 11:10:20+0100 [ttyACM1] 'reference': 11,
2012-03-07 11:10:20+0100 [ttyACM1] 'sequence': 1}
2012-03-07 11:10:20+0100 [ttyACM1]
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms first part of a multi part SMS added with logical index 6
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms: { 'completed': False,
2012-03-07 11:10:20+0100 [ttyACM1] 'count': 2,
2012-03-07 11:10:20+0100 [ttyACM1] 'csca': '+491722270333',
2012-03-07 11:10:20+0100 [ttyACM1] 'datetime': datetime.datetime(2012, 3, 7, 7, 21, 34, tzinfo=<UTC>),
2012-03-07 11:10:20+0100 [ttyACM1] 'fragments': [ ( 2,
2012-03-07 11:10:20+0100 [ttyACM1] u'fe kosten bis zu 60 Minuten 75 Ct/Anruf. www.vodafone.de')],
2012-03-07 11:10:20+0100 [ttyACM1] 'index': 7,
2012-03-07 11:10:20+0100 [ttyACM1] 'number': '12220',
2012-03-07 11:10:20+0100 [ttyACM1] 'real_indexes': set(),
2012-03-07 11:10:20+0100 [ttyACM1] 'reference': 11,
2012-03-07 11:10:20+0100 [ttyACM1] 'sequence': 2}
2012-03-07 11:10:20+0100 [ttyACM1]
2012-03-07 11:10:20+0100 [ttyACM1] MAL: Assembling fragment { 'completed': False,
2012-03-07 11:10:20+0100 [ttyACM1] 'count': 2,
2012-03-07 11:10:20+0100 [ttyACM1] 'csca': '+491722270333',
2012-03-07 11:10:20+0100 [ttyACM1] 'datetime': datetime.datetime(2012, 3, 7, 7, 21, 34, tzinfo=<UTC>),
2012-03-07 11:10:20+0100 [ttyACM1] 'fragments': [ ( 2,
2012-03-07 11:10:20+0100 [ttyACM1] u'fe kosten bis zu 60 Minuten 75 Ct/Anruf. www.vodafone.de')],
2012-03-07 11:10:20+0100 [ttyACM1] 'index': 7,
2012-03-07 11:10:20+0100 [ttyACM1] 'number': '12220',
2012-03-07 11:10:20+0100 [ttyACM1] 'real_indexes': set(),
2012-03-07 11:10:20+0100 [ttyACM1] 'reference': 11,
2012-03-07 11:10:20+0100 [ttyACM1] 'sequence': 2}
2012-03-07 11:10:20+0100 [ttyACM1] with sms { 'completed': False,
2012-03-07 11:10:20+0100 [ttyACM1] 'count': 2,
2012-03-07 11:10:20+0100 [ttyACM1] 'csca': '+491722270333',
2012-03-07 11:10:20+0100 [ttyACM1] 'datetime': datetime.datetime(2012, 3, 7, 7, 21, 33, tzinfo=<UTC>),
2012-03-07 11:10:20+0100 [ttyACM1] 'fragments': [ ( 1,
2012-03-07 11:10:20+0100 [ttyACM1] u'Willkommen in der Schweiz! Mit Ihrem Vodafone ReiseVersprechen kosten Anrufe nach Deutschland und in der Schweiz 29 Ct/Min + 75 Ct/Anruf. Ankommende Anru')],
2012-03-07 11:10:20+0100 [ttyACM1] 'index': 6,
2012-03-07 11:10:20+0100 [ttyACM1] 'number': '12220',
2012-03-07 11:10:20+0100 [ttyACM1] 'real_indexes': set([6]),
2012-03-07 11:10:20+0100 [ttyACM1] 'reference': 11,
2012-03-07 11:10:20+0100 [ttyACM1] 'sequence': 1}
2012-03-07 11:10:20+0100 [ttyACM1]
2012-03-07 11:10:20+0100 [ttyACM1] MAL::_add_sms multi part SMS with logical index 6, completed True
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CREG=1'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [-] Simple SM: begin exited
2012-03-07 11:10:20+0100 [-] Simple SM: check_pin entered
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CPIN?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CPIN: READY\r\n'
2012-03-07 11:10:20+0100 [ttyACM1] waiting: callback = [('READY',)]
2012-03-07 11:10:20+0100 [ttyACM1] Simple SM: check_pin exited
2012-03-07 11:10:20+0100 [ttyACM1] Simple SM: register entered
2012-03-07 11:10:20+0100 [ttyACM1] Simple SM: register exited
2012-03-07 11:10:20+0100 [ttyACM1] Simple SM: set_apn entered
2012-03-07 11:10:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:20+0100 [ttyACM1] idle: sending 'AT+CGDCONT?'
2012-03-07 11:10:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:21+0100 [ttyACM1] waiting: unmatched data '\r\n+CGDCONT: 1,"00490050","007700650062002E0076006F006400610066006F006E0065002E00640065","0030002E0030002E0030002E0030",0,0\r\n'
2012-03-07 11:10:21+0100 [ttyACM1] waiting: callback = [('1', '007700650062002E0076006F006400610066006F006E0065002E00640065', '0030002E0030002E0030002E0030')]
2012-03-07 11:10:21+0100 [ttyACM1] Simple SM: set_apn exited
2012-03-07 11:10:21+0100 [ttyACM1] Simple SM: set_band entered
2012-03-07 11:10:21+0100 [ttyACM1] Simple SM: set_band exited
2012-03-07 11:10:21+0100 [ttyACM1] Simple SM: set_allowed_mode entered
2012-03-07 11:10:21+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:21+0100 [ttyACM1] idle: sending 'AT+CFUN?'
2012-03-07 11:10:21+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:21+0100 [ttyACM1] waiting: unmatched data '\r\n+CFUN: 5\r\n'
2012-03-07 11:10:21+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:10:21+0100 [ttyACM1] Simple SM: set_allowed_mode is current
2012-03-07 11:10:21+0100 [ttyACM1] Simple SM: set_allowed_mode exited
2012-03-07 11:10:21+0100 [ttyACM1] Simple SM: wait_for_registration entered
2012-03-07 11:10:21+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:21+0100 [ttyACM1] idle: sending 'AT+CREG?'
2012-03-07 11:10:21+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:21+0100 [ttyACM1] waiting: unmatched data '\r\n+CREG: 1,5\r\n'
2012-03-07 11:10:21+0100 [ttyACM1] waiting: callback = [('1', '5', None)]
2012-03-07 11:10:21+0100 [ttyACM1] Simple SM: wait_for_registration exited
2012-03-07 11:10:21+0100 [ttyACM1] Simple SM: connect entered
2012-03-07 11:10:21+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem {'LastApn': u'web.vodafone.de'}
2012-03-07 11:10:21+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:21+0100 [ttyACM1] idle: sending 'AT*EIAAUW=1,1,"","",00010'
2012-03-07 11:10:21+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:21+0100 [ttyACM1] waiting: callback = [('OK',)]
2012-03-07 11:10:21+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem {'Enabled': dbus.Boolean(True)}
2012-03-07 11:10:21+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem {'State': dbus.UInt32(80L)}
2012-03-07 11:10:21+0100 [ttyACM1] emitting StateChanged(60, 80, 0)
2012-03-07 11:10:21+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:21+0100 [ttyACM1] idle: sending 'AT*ENAP=1,1'
2012-03-07 11:10:21+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:21+0100 [ttyACM1] '+CME ERROR: 277' didn't map to any of my keys
Traceback (most recent call last):
Failure: exceptions.KeyError: '+CME ERROR: 277'
2012-03-07 11:10:21+0100 [ttyACM1] waiting: unmatched data '\r\n+CME ERROR: 277\r\n'
2012-03-07 11:10:36+0100 [-] Unhandled error in Deferred:
2012-03-07 11:10:36+0100 [-] Unhandled Error
Traceback (most recent call last):
Failure: wader.common.aterrors.SerialResponseTimeout: org.freedesktop.ModemManager.Modem.SerialResponseTimeout: Command '<ATCmd name: send_at raw: 'AT*ENAP=1,1\r\n' timeout: 15>' timed out, this is my waitbuf:
+CME ERROR: 277
2012-03-07 11:10:36+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:36+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:10:36+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:36+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:10:36+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:10:36+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:10:36+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:10:50+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:10:50+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:10:50+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:10:50+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:10:50+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:10:50+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:11:05+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:11:05+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:11:05+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:11:05+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:11:05+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:11:05+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:11:20+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:11:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:11:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:11:20+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:11:20+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:11:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:11:35+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:11:35+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:11:35+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:11:35+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:11:35+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:11:35+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:11:50+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:11:50+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:11:50+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:11:50+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:11:50+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:11:50+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:12:05+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:12:05+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:12:05+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:12:05+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:12:05+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:12:05+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:12:20+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:12:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:12:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:12:20+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:12:20+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:12:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:12:20+0100 [ttyACM1] idle: sending 'AT+CREG?'
2012-03-07 11:12:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:12:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CREG: 1,5\r\n'
2012-03-07 11:12:20+0100 [ttyACM1] waiting: callback = [('1', '5', None)]
2012-03-07 11:12:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:12:20+0100 [ttyACM1] idle: sending 'AT+COPS=3,2;+COPS?'
2012-03-07 11:12:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:12:20+0100 [ttyACM1] waiting: unmatched data '\r\n+COPS: 0,2,"00320032003800300031",0 \r\n'
2012-03-07 11:12:20+0100 [ttyACM1] waiting: callback = [('0,2,"00320032003800300031",0', None, '00320032003800300031', '0')]
2012-03-07 11:12:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Network {'AccessTechnology': dbus.UInt32(3L)}
2012-03-07 11:12:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:12:20+0100 [ttyACM1] idle: sending 'AT+COPS=3,0;+COPS?'
2012-03-07 11:12:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:12:20+0100 [ttyACM1] waiting: unmatched data '\r\n+COPS: 0,0,"005300770069007300730063006F006D",0 \r\n'
2012-03-07 11:12:20+0100 [ttyACM1] waiting: callback = [('0,0,"005300770069007300730063006F006D",0', None, '005300770069007300730063006F006D', '0')]
2012-03-07 11:12:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Network {'AccessTechnology': dbus.UInt32(3L)}
2012-03-07 11:12:20+0100 [ttyACM1] emitting RegistrationInfo(5, '22801', 'Swisscom')
2012-03-07 11:12:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:12:35+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:12:35+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:12:35+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:12:35+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:12:35+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:12:35+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:12:50+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:12:50+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:12:50+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:12:50+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:12:50+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:12:50+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:13:05+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:13:05+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:13:05+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:13:05+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:13:05+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:13:05+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:13:11+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:13:12+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:13:18+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:13:19+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:13:20+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:13:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:13:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:13:20+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:13:20+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:13:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:13:22+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:13:23+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:13:35+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:13:35+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:13:35+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:13:35+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:13:35+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:13:35+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:13:48+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:13:50+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:13:50+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:13:50+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,4,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:13:50+0100 [ttyACM1] waiting: callback = [('4',)]
2012-03-07 11:13:50+0100 [ttyACM1] emitting SignalQuality(80)
2012-03-07 11:13:50+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:14:00+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:14:01+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:14:05+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:14:05+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:14:05+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,4,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:14:05+0100 [ttyACM1] waiting: callback = [('4',)]
2012-03-07 11:14:05+0100 [ttyACM1] emitting SignalQuality(80)
2012-03-07 11:14:05+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:14:06+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:14:20+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:14:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:14:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:14:20+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:14:20+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:14:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:14:20+0100 [ttyACM1] idle: sending 'AT+CREG?'
2012-03-07 11:14:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:14:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CREG: 1,5\r\n'
2012-03-07 11:14:20+0100 [ttyACM1] waiting: callback = [('1', '5', None)]
2012-03-07 11:14:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:14:20+0100 [ttyACM1] idle: sending 'AT+COPS=3,2;+COPS?'
2012-03-07 11:14:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:14:20+0100 [ttyACM1] waiting: unmatched data '\r\n+COPS: 0,2,"00320032003800300031",0 \r\n'
2012-03-07 11:14:20+0100 [ttyACM1] waiting: callback = [('0,2,"00320032003800300031",0', None, '00320032003800300031', '0')]
2012-03-07 11:14:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Network {'AccessTechnology': dbus.UInt32(3L)}
2012-03-07 11:14:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:14:20+0100 [ttyACM1] idle: sending 'AT+COPS=3,0;+COPS?'
2012-03-07 11:14:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:14:20+0100 [ttyACM1] waiting: unmatched data '\r\n+COPS: 0,0,"005300770069007300730063006F006D",0 \r\n'
2012-03-07 11:14:20+0100 [ttyACM1] waiting: callback = [('0,0,"005300770069007300730063006F006D",0', None, '005300770069007300730063006F006D', '0')]
2012-03-07 11:14:20+0100 [ttyACM1] emitting MmPropertiesChanged: org.freedesktop.ModemManager.Modem.Gsm.Network {'AccessTechnology': dbus.UInt32(3L)}
2012-03-07 11:14:20+0100 [ttyACM1] emitting RegistrationInfo(5, '22801', 'Swisscom')
2012-03-07 11:14:20+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:14:28+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:14:30+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:14:31+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:14:35+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:14:35+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:14:35+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,4,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:14:35+0100 [ttyACM1] waiting: callback = [('4',)]
2012-03-07 11:14:35+0100 [ttyACM1] emitting SignalQuality(80)
2012-03-07 11:14:35+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:14:39+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:14:40+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:14:45+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:14:46+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:14:47+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:14:49+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:14:50+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:14:50+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:14:50+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,4,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:14:50+0100 [ttyACM1] waiting: callback = [('4',)]
2012-03-07 11:14:50+0100 [ttyACM1] emitting SignalQuality(80)
2012-03-07 11:14:50+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:15:02+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:15:02+0100 [ttyACM1] idle: '\r\n+CIEV: 2,4\r\n'
2012-03-07 11:15:04+0100 [ttyACM1] idle: '\r\n+CIEV: 2,5\r\n'
2012-03-07 11:15:05+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:15:05+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:15:05+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:15:05+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:15:05+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:15:05+0100 [ttyACM1] state change: waiting -> idle
2012-03-07 11:15:20+0100 [ttyACM1] idle: sending 'AT+CIND?'
2012-03-07 11:15:20+0100 [ttyACM1] state change: idle -> waiting
2012-03-07 11:15:20+0100 [ttyACM1] waiting: unmatched data '\r\n+CIND: 5,5,0,0,1,0,0,0,1,0,0,0\r\n'
2012-03-07 11:15:20+0100 [ttyACM1] waiting: callback = [('5',)]
2012-03-07 11:15:20+0100 [ttyACM1] emitting SignalQuality(100)
2012-03-07 11:15:20+0100 [ttyACM1] state change: waiting -> idle
@andrewbird
Copy link

Hi Thomas,
It looks like you managed to connect last time, but the Wader didn't wait long enough. The error 277 you see this time means 'Not disconnected' or to paraphrase; 'you can't connect because you are already connected'. Maybe increase the number of times that Wader polls the device for connection status from 5 to 10, that's the HSO_MAX_RETRIES variable in core/hardware/ericsson.py, then reboot just to make sure you really are disconnected.
It looks like NM isn't passing the PAP/CHAP auth info in the properties dict to Wader during the SimpleConnect() dbus call. For now you might want to hardcode that value in the 'hso_authenticate' method to CHAP, that might speed up your connection process, so look for it in core/hardware/ericsson.py.

Regarding tagging, can I delay a couple of days as one of my guys is looking at a problem with 12.04 twisted threading and I think we might need to add a workaround for Wader? I also need to sort out tag signing, as currently I'm not in Debian's web of trust.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment