rendered paste body2009-02-01 17:47:15+0000 [-] Log opened.
2009-02-01 17:47:15+0000 [-] twistd 8.0.1 (/usr/bin/python 2.5.2) starting up
2009-02-01 17:47:15+0000 [-] reactor class: <class 'twisted.internet.gtk2reactor.Gtk2Reactor'>
2009-02-01 17:47:15+0000 [-] Changing process name to VMCCdfL
2009-02-01 17:47:18+0000 [-] Log opened.
2009-02-01 17:47:18+0000 [-] twistd 8.0.1 (/home/robert/ 2.5.2) starting up
2009-02-01 17:47:18+0000 [-] reactor class: <class 'twisted.internet.gtk2reactor.Gtk2Reactor'>
2009-02-01 17:47:24+0000 [-] AT+CGMM response: ['E160X', 'OK']
2009-02-01 17:47:24+0000 [-] /usr/lib/python2.5/site-packages/vmc/gtk/views/application.py:291: gtk.GtkWarning: gtk_widget_size_allocate(): attempt to allocate widget with width 588 and height -14
2009-02-01 17:47:24+0000 [-] ADAPTING <vmc.common.plugins.huawei_k3565.HuaweiK3565 object at 0x8ab570c> to <class 'vmc.common.middleware.SIMCardConnAdapter'>
2009-02-01 17:47:24+0000 [-] DAEMONS: DAEMON SignalQualityDaemon started...
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CSQ\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:24+0000 [-] DAEMONS: executing <bound method SignalQualityDaemon.function of <vmc.common.daemon.SignalQualityDaemon object at 0x8d88e0c>> every 60 seconds
2009-02-01 17:47:24+0000 [-] Instantiating AuthStateMachine ...
2009-02-01 17:47:24+0000 [-] AuthStateMachine: Instantiating get_pin_status mode....
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+CSQ: 17,99\r\n\r\nOK\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('17', '99')]
2009-02-01 17:47:24+0000 [-] AuthStateMachine: notification <UnsolicitedNotification type: rssi args: 17> received
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CPIN?\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+CPIN: READY\r\n\r\nOK\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('READY',)]
2009-02-01 17:47:24+0000 [-] GTKBehaviour: LEAVING Auth AND ENTERING INTO Init
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CSCS=?\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+CSCS: ("IRA","GSM","UCS2")\r\n\r\nOK\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('IRA',), ('GSM',), ('UCS2',)]
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CNMI=2,1,0,0,0\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\nOK\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: CBK = [()]
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CMGF=0\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\nOK\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: CBK = [()]
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CPBR=?\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+CPBR: (1-250),24,14\r\n\r\nOK\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('250',)]
2009-02-01 17:47:24+0000 [-] Setting size to 250
2009-02-01 17:47:24+0000 [-] GTKBehaviour: LEAVING Init AND ENTERING INTO NetReg
2009-02-01 17:47:24+0000 [-] Instantiating NetworkRegStateMachine ....
2009-02-01 17:47:24+0000 [-] NetworkRegStateMachine: NEW MODE: check_registered
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CSCS?\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+CSCS: "IRA"\r\n\r\nOK\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('IRA',)]
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CIMI\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n234159068139668\r\n\r\nOK\r\n'
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:24+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('234159068139668',)]
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CSCS="IRA"\r\n'
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\nOK\r\n'
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING: CBK = [()]
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CREG?\r\n'
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+CREG: 0,1\r\n\r\nOK\r\n'
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('0', '1')]
2009-02-01 17:47:33+0000 [-] NetworkRegStateMachine: NEW MODE: registration_finished
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CSCS="UCS2"\r\n'
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\nOK\r\n'
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING: CBK = [()]
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CSCS="UCS2"\r\n'
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\nOK\r\n'
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING: CBK = [()]
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+COPS?\r\n'
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+COPS: 0,0,"vodafone UK",2\r\n\r\nOK\r\n'
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('0,0,"vodafone UK",2', None, 'vodafone UK', '2')]
2009-02-01 17:47:33+0000 [-] GTKBehaviour: LEAVING NetReg AND ENTERING INTO ImDone
2009-02-01 17:47:33+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:38+0000 [-] /usr/lib/python2.5/site-packages/vmc/gtk/controllers/application.py:235: gtk.GtkWarning: gtk_widget_set_events: assertion `!GTK_WIDGET_REALIZED (widget)' failed
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CPBR=1,250\r\n'
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\nERROR\r\n'
2009-02-01 17:47:38+0000 [-] "SIMCardConnAdapter::WAITING: ERROR received '\\r\\nERROR\\r\\n'"
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CMGL=4\r\n'
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\nOK\r\n'
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter::WAITING: CBK = []
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CLCK="SC",2\r\n'
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+CLCK: 0\r\n\r\nOK\r\n'
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('0',)]
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CLCK="SC",2\r\n'
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+CLCK: 0\r\n\r\nOK\r\n'
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('0',)]
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CSQ\r\n'
2009-02-01 17:47:38+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:39+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+CSQ: 17,99\r\n\r\nOK\r\n'
2009-02-01 17:47:39+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:39+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('17', '99')]
2009-02-01 17:47:39+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:39+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+COPS?\r\n'
2009-02-01 17:47:39+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:39+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+COPS: 0,0,"vodafone UK",2\r\n\r\nOK\r\n'
2009-02-01 17:47:39+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:39+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('0,0,"vodafone UK",2', None, 'vodafone UK', '2')]
2009-02-01 17:47:39+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:47+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+COPS?\r\n'
2009-02-01 17:47:47+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:47+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+COPS: 0,0,"vodafone UK",2\r\n\r\nOK\r\n'
2009-02-01 17:47:47+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:47+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('0,0,"vodafone UK",2', None, 'vodafone UK', '2')]
2009-02-01 17:47:47+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV --> WvDial: Internet dialer version 1.60
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV --> Cannot get information for serial port.
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV
--> Initializing modem.
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV --> Sending: ATZ
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV OK
--> Sending: ATZ
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV ATZ
OK
--> Sending: ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
OK
--> Sending: AT+CGDCONT=1,"IP","internet"
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV OK
--> Modem initialized.
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV --> Sending: ATDT*99***1#
--> Waiting for carrier.
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV CONNECT
--> Carrier detected. Starting PPP immediately.
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV --> Starting pppd at Sun Feb 1 17:47:47 2009
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV --> Pid of pppd: 4122
2009-02-01 17:47:47+0000 [-] WVDIAL: DATA RECV --> Using interface ppp0
--> Authentication (CHAP) started
--> Authentication (CHAP) successful
2009-02-01 17:47:47+0000 [-] "Notification <ConnectionNotification at 0x8d998ac status: connected> not in {'call': None, 'rssi': <bound method ApplicationController._change_signal_level of <vmc.gtk.controllers.application.ApplicationController object at 0x8cabd0c>>, 'sms': <bound method ApplicationController._on_sms_received of <vmc.gtk.controllers.application.ApplicationController object at 0x8cabd0c>>, 'new_conn_mode': <bound method ApplicationController._conn_mode_changed of <vmc.gtk.controllers.application.ApplicationController object at 0x8cabd0c>>, 'rfswitch': <bound method ApplicationController._change_radio_state of <vmc.gtk.controllers.application.ApplicationController object at 0x8cabd0c>>, 'speed': <bound method ApplicationController._change_net_stats_cb of <vmc.gtk.controllers.application.ApplicationController object at 0x8cabd0c>>}"
2009-02-01 17:47:47+0000 [-] ConnectionTracker started........
2009-02-01 17:47:47+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+COPS?\r\n'
2009-02-01 17:47:47+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:47:48+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+COPS: 0,0,"vodafone UK",2\r\n\r\nOK\r\n'
2009-02-01 17:47:48+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:47:48+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('0,0,"vodafone UK",2', None, 'vodafone UK', '2')]
2009-02-01 17:47:48+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:47:48+0000 [-] SIMCardConnAdapter::IDLE DATA_RCV: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:47:48+0000 [-] SIMCardConnAdapter::Huawei K3565 NOTIFICATION: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:47:49+0000 [-] SIMCardConnAdapter::IDLE DATA_RCV: '\r\n^RSSI:17\r\n'
2009-02-01 17:47:49+0000 [-] SIMCardConnAdapter::Huawei K3565 NOTIFICATION: '\r\n^RSSI:17\r\n'
2009-02-01 17:47:49+0000 [-] SIMCardConnAdapter: QUEING <class 'vmc.common.notifications.UnsolicitedNotification'> args=('rssi', 17) kwds={}
2009-02-01 17:47:49+0000 [-] WVDIAL: DATA RECV --> Disconnecting at Sun Feb 1 17:47:49 2009
2009-02-01 17:47:49+0000 [-] WVDIAL: DATA RECV --> The PPP daemon has died: A modem hung up the phone (exit code = 16)
--> man pppd explains pppd error codes in more detail.
--> Try again and look into /var/log/messages and the wvdial and pppd man pages for more information.
--> Auto Reconnect will be attempted in 5 seconds
2009-02-01 17:47:49+0000 [-] "disconnected_handler this shouldn't happen"
2009-02-01 17:47:49+0000 [-] WVDIAL: DATA RECV --> Cannot get information for serial port.
2009-02-01 17:47:49+0000 [-] WVDIAL: DATA RECV
--> Initializing modem.
2009-02-01 17:47:49+0000 [-] WVDIAL: DATA RECV --> Sending: ATZ
2009-02-01 17:47:49+0000 [-] WVDIAL: DATA RECV OK
--> Sending: ATZ
2009-02-01 17:47:50+0000 [-] WVDIAL: DATA RECV ATZ
OK
--> Sending: ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
2009-02-01 17:47:50+0000 [-] WVDIAL: DATA RECV ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
OK
--> Sending: AT+CGDCONT=1,"IP","internet"
2009-02-01 17:47:50+0000 [-] WVDIAL: DATA RECV OK
--> Modem initialized.
2009-02-01 17:47:50+0000 [-] SIMCardConnAdapter::IDLE DATA_RCV: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:47:50+0000 [-] SIMCardConnAdapter::Huawei K3565 NOTIFICATION: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:47:52+0000 [-] SIMCardConnAdapter::IDLE DATA_RCV: '\r\n^RSSI:17\r\n'
2009-02-01 17:47:52+0000 [-] SIMCardConnAdapter::Huawei K3565 NOTIFICATION: '\r\n^RSSI:17\r\n'
2009-02-01 17:47:52+0000 [-] SIMCardConnAdapter: QUEING <class 'vmc.common.notifications.UnsolicitedNotification'> args=('rssi', 17) kwds={}
2009-02-01 17:47:54+0000 [-] WVDIAL: DATA RECV --> Cannot get information for serial port.
2009-02-01 17:47:54+0000 [-] WVDIAL: DATA RECV
--> Initializing modem.
2009-02-01 17:47:54+0000 [-] WVDIAL: DATA RECV --> Sending: ATZ
2009-02-01 17:47:54+0000 [-] WVDIAL: DATA RECV OK
--> Sending: ATZ
2009-02-01 17:47:54+0000 [-] WVDIAL: DATA RECV ATZ
OK
--> Sending: ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
2009-02-01 17:47:54+0000 [-] WVDIAL: DATA RECV ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
OK
--> Sending: AT+CGDCONT=1,"IP","internet"
2009-02-01 17:47:54+0000 [-] WVDIAL: DATA RECV OK
--> Modem initialized.
2009-02-01 17:47:54+0000 [-] WVDIAL: DATA RECV --> Sending: ATDT*99***1#
--> Waiting for carrier.
2009-02-01 17:47:55+0000 [-] WVDIAL: DATA RECV CONNECT
--> Carrier detected. Starting PPP immediately.
--> Starting pppd at Sun Feb 1 17:47:55 2009
2009-02-01 17:47:55+0000 [-] WVDIAL: DATA RECV --> Pid of pppd: 4132
2009-02-01 17:47:55+0000 [-] WVDIAL: DATA RECV --> Using interface ppp0
--> Authentication (CHAP) started
--> Authentication (CHAP) successful
2009-02-01 17:47:55+0000 [-] SIMCardConnAdapter::IDLE DATA_RCV: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:47:55+0000 [-] SIMCardConnAdapter::Huawei K3565 NOTIFICATION: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:47:56+0000 [-] WVDIAL: DATA RECV --> Disconnecting at Sun Feb 1 17:47:56 2009
2009-02-01 17:47:56+0000 [-] WVDIAL: DATA RECV --> The PPP daemon has died: A modem hung up the phone (exit code = 16)
--> man pppd explains pppd error codes in more detail.
--> Try again and look into /var/log/messages and the wvdial and pppd man pages for more information.
--> Auto Reconnect will be attempted in 10 seconds
2009-02-01 17:47:56+0000 [-] "disconnected_handler this shouldn't happen"
2009-02-01 17:47:56+0000 [-] WVDIAL: DATA RECV --> Cannot get information for serial port.
2009-02-01 17:47:56+0000 [-] WVDIAL: DATA RECV
--> Initializing modem.
2009-02-01 17:47:57+0000 [-] WVDIAL: DATA RECV --> Sending: ATZ
2009-02-01 17:47:57+0000 [-] WVDIAL: DATA RECV OK
--> Sending: ATZ
2009-02-01 17:47:57+0000 [-] WVDIAL: DATA RECV ATZ
OK
--> Sending: ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
2009-02-01 17:47:57+0000 [-] WVDIAL: DATA RECV ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
OK
--> Sending: AT+CGDCONT=1,"IP","internet"
2009-02-01 17:47:57+0000 [-] WVDIAL: DATA RECV OK
--> Modem initialized.
2009-02-01 17:47:58+0000 [-] SIMCardConnAdapter::IDLE DATA_RCV: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:47:58+0000 [-] SIMCardConnAdapter::Huawei K3565 NOTIFICATION: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:48:06+0000 [-] WVDIAL: DATA RECV --> Cannot get information for serial port.
2009-02-01 17:48:06+0000 [-] WVDIAL: DATA RECV
--> Initializing modem.
2009-02-01 17:48:06+0000 [-] WVDIAL: DATA RECV --> Sending: ATZ
2009-02-01 17:48:06+0000 [-] WVDIAL: DATA RECV OK
--> Sending: ATZ
2009-02-01 17:48:06+0000 [-] WVDIAL: DATA RECV ATZ
OK
--> Sending: ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
2009-02-01 17:48:06+0000 [-] WVDIAL: DATA RECV ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
OK
--> Sending: AT+CGDCONT=1,"IP","internet"
2009-02-01 17:48:06+0000 [-] WVDIAL: DATA RECV OK
--> Modem initialized.
2009-02-01 17:48:06+0000 [-] WVDIAL: DATA RECV --> Sending: ATDT*99***1#
--> Waiting for carrier.
2009-02-01 17:48:07+0000 [-] SIMCardConnAdapter::IDLE DATA_RCV: '\r\n^RSSI:14\r\n'
2009-02-01 17:48:07+0000 [-] SIMCardConnAdapter::Huawei K3565 NOTIFICATION: '\r\n^RSSI:14\r\n'
2009-02-01 17:48:07+0000 [-] SIMCardConnAdapter: QUEING <class 'vmc.common.notifications.UnsolicitedNotification'> args=('rssi', 14) kwds={}
2009-02-01 17:48:07+0000 [-] WVDIAL: DATA RECV CONNECT
--> Carrier detected. Starting PPP immediately.
--> Starting pppd at Sun Feb 1 17:48:07 2009
2009-02-01 17:48:07+0000 [-] WVDIAL: DATA RECV --> Pid of pppd: 4142
2009-02-01 17:48:07+0000 [-] WVDIAL: DATA RECV --> Using interface ppp0
--> Authentication (CHAP) started
--> Authentication (CHAP) successful
2009-02-01 17:48:07+0000 [-] SIMCardConnAdapter::IDLE DATA_RCV: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:48:07+0000 [-] SIMCardConnAdapter::Huawei K3565 NOTIFICATION: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:48:08+0000 [-] WVDIAL: DATA RECV --> Disconnecting at Sun Feb 1 17:48:08 2009
2009-02-01 17:48:08+0000 [-] WVDIAL: DATA RECV --> The PPP daemon has died: A modem hung up the phone (exit code = 16)
--> man pppd explains pppd error codes in more detail.
--> Try again and look into /var/log/messages and the wvdial and pppd man pages for more information.
--> Auto Reconnect will be attempted in 20 seconds
2009-02-01 17:48:08+0000 [-] "disconnected_handler this shouldn't happen"
2009-02-01 17:48:08+0000 [-] WVDIAL: DATA RECV --> Cannot get information for serial port.
2009-02-01 17:48:08+0000 [-] WVDIAL: DATA RECV
--> Initializing modem.
2009-02-01 17:48:09+0000 [-] WVDIAL: DATA RECV --> Sending: ATZ
2009-02-01 17:48:09+0000 [-] WVDIAL: DATA RECV OK
--> Sending: ATZ
2009-02-01 17:48:09+0000 [-] WVDIAL: DATA RECV ATZ
OK
--> Sending: ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
2009-02-01 17:48:09+0000 [-] WVDIAL: DATA RECV ATQ0 V1 E0 S0=0 &C1 &D2 +FCLASS=0
OK
--> Sending: AT+CGDCONT=1,"IP","internet"
2009-02-01 17:48:09+0000 [-] WVDIAL: DATA RECV OK
--> Modem initialized.
2009-02-01 17:48:10+0000 [-] SIMCardConnAdapter::IDLE DATA_RCV: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:48:10+0000 [-] SIMCardConnAdapter::Huawei K3565 NOTIFICATION: '\r\n^BOOT:23831710,0,0,0,77\r\n'
2009-02-01 17:48:19+0000 [-] "Notification <ConnectionNotification at 0x8ee58cc status: disconnected> not in {'call': None, 'rssi': <bound method ApplicationController._change_signal_level of <vmc.gtk.controllers.application.ApplicationController object at 0x8cabd0c>>, 'sms': <bound method ApplicationController._on_sms_received of <vmc.gtk.controllers.application.ApplicationController object at 0x8cabd0c>>, 'new_conn_mode': <bound method ApplicationController._conn_mode_changed of <vmc.gtk.controllers.application.ApplicationController object at 0x8cabd0c>>, 'rfswitch': <bound method ApplicationController._change_radio_state of <vmc.gtk.controllers.application.ApplicationController object at 0x8cabd0c>>, 'speed': <bound method ApplicationController._change_net_stats_cb of <vmc.gtk.controllers.application.ApplicationController object at 0x8cabd0c>>}"
2009-02-01 17:48:19+0000 [-] WVDIAL: DATA RECV Caught signal 15: Attempting to exit gracefully...
2009-02-01 17:48:19+0000 [-] 'EXIT CODE 1'
2009-02-01 17:48:19+0000 [-] WVDIAL: DATA RECV --> Disconnecting at Sun Feb 1 17:48:19 2009
2009-02-01 17:48:19+0000 [-] WVDIAL: pppd closed their stdout!
2009-02-01 17:48:19+0000 [-] WVDIAL: pppd closed their stderr.
2009-02-01 17:48:19+0000 [-] WVDIAL: quitting
2009-02-01 17:48:24+0000 [-] SIMCardConnAdapter: SENDING ATCMD 'AT+CSQ\r\n'
2009-02-01 17:48:24+0000 [-] SIMCardConnAdapter: NEW STATE: waiting
2009-02-01 17:48:24+0000 [-] SIMCardConnAdapter::WAITING DATA_RCV: '\r\n+CSQ: 14,99\r\n\r\nOK\r\n'
2009-02-01 17:48:24+0000 [-] SIMCardConnAdapter::WAITING: EOR detected, firing deferred
2009-02-01 17:48:24+0000 [-] SIMCardConnAdapter::WAITING: CBK = [('14', '99')]
2009-02-01 17:48:24+0000 [-] SIMCardConnAdapter: NEW STATE: idle
2009-02-01 17:48:27+0000 [-] Shutting down...
2009-02-01 17:48:27+0000 [-] Server Shut Down.
2009-02-01 17:48:27+0000 [-] Unhandled error in Deferred:
2009-02-01 17:48:27+0000 [-] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.5/site-packages/twisted/internet/process.py", line 332, in maybeCallProcessEnded
self.proto.processEnded(failure.Failure(e))
File "/usr/lib/python2.5/site-packages/twisted/internet/utils.py", line 51, in processEnded
self.deferred.callback(self.s.getvalue())
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 242, in callback
self._startRunCallbacks(result)
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 307, in _startRunCallbacks
self._runCallbacks()
--- <exception caught here> ---
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 323, in _runCallbacks
self.result = callback(self.result, *args, **kw)
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/common/statem/connection.py", line 113, in get_iface_stats_cb
exceptions.TypeError: unsupported operand type(s) for -: 'NoneType' and 'int'
2009-02-01 17:48:27+0000 [-] Unhandled error in Deferred:
2009-02-01 17:48:27+0000 [-] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.5/site-packages/twisted/internet/process.py", line 332, in maybeCallProcessEnded
self.proto.processEnded(failure.Failure(e))
File "/usr/lib/python2.5/site-packages/twisted/internet/utils.py", line 51, in processEnded
self.deferred.callback(self.s.getvalue())
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 242, in callback
self._startRunCallbacks(result)
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 307, in _startRunCallbacks
self._runCallbacks()
--- <exception caught here> ---
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 323, in _runCallbacks
self.result = callback(self.result, *args, **kw)
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/common/statem/connection.py", line 113, in get_iface_stats_cb
exceptions.TypeError: unsupported operand type(s) for -: 'NoneType' and 'int'
2009-02-01 17:48:27+0000 [-] Unhandled error in Deferred:
2009-02-01 17:48:27+0000 [-] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.5/site-packages/twisted/internet/process.py", line 332, in maybeCallProcessEnded
self.proto.processEnded(failure.Failure(e))
File "/usr/lib/python2.5/site-packages/twisted/internet/utils.py", line 51, in processEnded
self.deferred.callback(self.s.getvalue())
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 242, in callback
self._startRunCallbacks(result)
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 307, in _startRunCallbacks
self._runCallbacks()
--- <exception caught here> ---
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 323, in _runCallbacks
self.result = callback(self.result, *args, **kw)
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/common/statem/connection.py", line 113, in get_iface_stats_cb
exceptions.TypeError: unsupported operand type(s) for -: 'NoneType' and 'int'
2009-02-01 17:48:27+0000 [-] Unhandled error in Deferred:
2009-02-01 17:48:27+0000 [-] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.5/site-packages/twisted/internet/process.py", line 332, in maybeCallProcessEnded
self.proto.processEnded(failure.Failure(e))
File "/usr/lib/python2.5/site-packages/twisted/internet/utils.py", line 51, in processEnded
self.deferred.callback(self.s.getvalue())
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 242, in callback
self._startRunCallbacks(result)
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 307, in _startRunCallbacks
self._runCallbacks()
--- <exception caught here> ---
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 323, in _runCallbacks
self.result = callback(self.result, *args, **kw)
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/common/statem/connection.py", line 113, in get_iface_stats_cb
exceptions.TypeError: unsupported operand type(s) for -: 'NoneType' and 'int'
2009-02-01 17:48:27+0000 [-] Unhandled error in Deferred:
2009-02-01 17:48:27+0000 [-] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.5/site-packages/twisted/internet/process.py", line 332, in maybeCallProcessEnded
self.proto.processEnded(failure.Failure(e))
File "/usr/lib/python2.5/site-packages/twisted/internet/utils.py", line 51, in processEnded
self.deferred.callback(self.s.getvalue())
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 242, in callback
self._startRunCallbacks(result)
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 307, in _startRunCallbacks
self._runCallbacks()
--- <exception caught here> ---
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 323, in _runCallbacks
self.result = callback(self.result, *args, **kw)
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/common/statem/connection.py", line 113, in get_iface_stats_cb
exceptions.TypeError: unsupported operand type(s) for -: 'NoneType' and 'int'
2009-02-01 17:48:27+0000 [-] Unhandled error in Deferred:
2009-02-01 17:48:27+0000 [-] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.5/site-packages/twisted/internet/process.py", line 332, in maybeCallProcessEnded
self.proto.processEnded(failure.Failure(e))
File "/usr/lib/python2.5/site-packages/twisted/internet/utils.py", line 51, in processEnded
self.deferred.callback(self.s.getvalue())
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 242, in callback
self._startRunCallbacks(result)
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 307, in _startRunCallbacks
self._runCallbacks()
--- <exception caught here> ---
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 323, in _runCallbacks
self.result = callback(self.result, *args, **kw)
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/common/statem/connection.py", line 113, in get_iface_stats_cb
exceptions.TypeError: unsupported operand type(s) for -: 'NoneType' and 'int'
2009-02-01 17:48:27+0000 [-] Unhandled error in Deferred:
2009-02-01 17:48:27+0000 [-] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.5/site-packages/twisted/internet/process.py", line 332, in maybeCallProcessEnded
self.proto.processEnded(failure.Failure(e))
File "/usr/lib/python2.5/site-packages/twisted/internet/utils.py", line 51, in processEnded
self.deferred.callback(self.s.getvalue())
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 242, in callback
self._startRunCallbacks(result)
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 307, in _startRunCallbacks
self._runCallbacks()
--- <exception caught here> ---
File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 323, in _runCallbacks
self.result = callback(self.result, *args, **kw)
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/common/statem/connection.py", line 96, in get_iface_stats_cb
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/common/persistent.py", line 307, in add_usage_item
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/contrib/axiom/item.py", line 523, in __init__
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/contrib/axiom/item.py", line 490, in __subinit__
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/contrib/axiom/slotmachine.py", line 161, in __setattr__
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/contrib/axiom/attributes.py", line 479, in __set__
File "./tmp/vodafone-mobile-connect-1.99.17/usr/lib/python2.5/site-packages/vmc/contrib/axiom/attributes.py", line 472, in _convertPyval
exceptions.TypeError: attribute [UsageItem.bits_sent = integer()] must not be None