May  1 16:47:45 calvino frameworkd.resource INFO     setting resource status for GSM from disabled to enabling
May  1 16:47:45 calvino ogsmd.modems DEBUG    requested to build modem 'ti_calypso'
May  1 16:47:45 calvino ogsmd.channel INFO     <CallChannel via unknown>: Creating channel with timeout = 3600 seconds
May  1 16:47:45 calvino ogsmd.channel INFO     <UnsolicitedResponseChannel via unknown>: Creating channel with timeout = 300 seconds
May  1 16:47:45 calvino ogsmd.channel INFO     <MiscChannel via unknown>: Creating channel with timeout = 300 seconds
May  1 16:47:45 calvino ogsmd.modem.abstract DEBUG    trying to open channel MISC
May  1 16:47:45 calvino ogsmd.modems.ti_calypso INFO     Requesting new channel from 'gsm0710muxd'
May  1 16:47:45 calvino gsm0710muxd: gsm0710muxd.c:1988:main(): using '/sys/bus/platform/devices/neo1973-pm-gsm.0' as basedir for pm
May  1 16:47:52 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1670:open_serial_device(): Opened serial port
May  1 16:47:52 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1694:open_serial_device(): Configured serial device
May  1 16:47:52 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1816:watchdog(): Watchdog started
May  1 16:47:52 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1705:start_muxer(): Configuring modem
May  1 16:47:53 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1709:start_muxer(): Modem does not respond to AT commands, trying close mux mode
May  1 16:47:53 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1749:start_muxer(): Starting mux mode
May  1 16:47:53 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1752:start_muxer(): Waiting for mux-mode
May  1 16:47:54 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1754:start_muxer(): Init control channel
May  1 16:47:55 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:729:c_alloc_channel(): Connecting /dev/pts/1 to virtual channel 1 for ogsmd.misc on /dev/ttySAC0
May  1 16:47:55 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1474:extract_frames(): Logical channel 1 opened
May  1 16:47:55 calvino ogsmd.channel INFO     <MiscChannel via unknown>: initializing
May  1 16:47:55 calvino ogsmd    DEBUG    (modem init... try #1)
May  1 16:47:55 calvino ogsmd    DEBUG    read: AT-Command Interpreter ready
May  1 16:47:55 calvino ogsmd    INFO     <MiscChannel via /dev/pts/1>: responding OK
May  1 16:47:55 calvino ogsmd.modem.abstract DEBUG    trying to open channel UNSOL
May  1 16:47:55 calvino ogsmd.modems.ti_calypso INFO     Requesting new channel from 'gsm0710muxd'
May  1 16:47:55 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:729:c_alloc_channel(): Connecting /dev/pts/2 to virtual channel 2 for ogsmd.unsolicited on /dev/ttySAC0
May  1 16:47:55 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1474:extract_frames(): Logical channel 2 opened
May  1 16:47:56 calvino ogsmd.channel INFO     <UnsolicitedResponseChannel via unknown>: initializing
May  1 16:47:56 calvino ogsmd    DEBUG    (modem init... try #1)
May  1 16:47:56 calvino ogsmd    DEBUG    read: AT-Command Interpreter ready
May  1 16:47:56 calvino ogsmd    INFO     <UnsolicitedResponseChannel via /dev/pts/2>: responding OK
May  1 16:47:56 calvino ogsmd.modem.abstract DEBUG    trying to open channel CALL
May  1 16:47:56 calvino ogsmd.modems.ti_calypso INFO     Requesting new channel from 'gsm0710muxd'
May  1 16:47:56 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:729:c_alloc_channel(): Connecting /dev/pts/6 to virtual channel 3 for ogsmd.call on /dev/ttySAC0
May  1 16:47:56 calvino /usr/sbin/gsm0710muxd[19027]: gsm0710muxd.c:1474:extract_frames(): Logical channel 3 opened
May  1 16:47:57 calvino ogsmd.channel INFO     <CallChannel via unknown>: initializing
May  1 16:47:57 calvino ogsmd    DEBUG    (modem init... try #1)
May  1 16:47:57 calvino ogsmd    DEBUG    read: AT-Command Interpreter ready
May  1 16:47:57 calvino ogsmd    INFO     <CallChannel via /dev/pts/6>: responding OK
May  1 16:47:57 calvino frameworkd.resource INFO     setting resource status for GSM from enabling to enabled
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 4 bytes: 'AT\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 4 bytes: 'AT\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 4 bytes: 'AT\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1528
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT' => ['OK']
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1529
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT' => ['OK']
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1530
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT' => ['OK']
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 5 bytes: 'ATZ\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 5 bytes: 'ATZ\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 5 bytes: 'ATZ\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1537
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'ATZ' => ['OK']
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1538
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'ATZ' => ['OK']
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1539
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'ATZ' => ['OK']
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 8 bytes: 'ATE0V1\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 8 bytes: 'ATE0V1\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:57 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 8 bytes: 'ATE0V1\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1546
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:57 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'ATE0V1' => ['OK']
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1547
May  1 16:47:57 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'ATE0V1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1548
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'ATE0V1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 11 bytes: 'AT+CMEE=1\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CMEE=1\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 11 bytes: 'AT+CMEE=1\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1555
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CMEE=1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1556
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CMEE=1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1557
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT+CMEE=1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 10 bytes: 'AT+CRC=1\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 10 bytes: 'AT+CRC=1\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 10 bytes: 'AT+CRC=1\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1564
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CRC=1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1565
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CRC=1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1566
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT+CRC=1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 16 bytes: 'AT+CSCS="UCS2"\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 16 bytes: 'AT+CSCS="UCS2"\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 16 bytes: 'AT+CSCS="UCS2"\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1573
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CSCS="UCS2"' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1574
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CSCS="UCS2"' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1575
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT+CSCS="UCS2"' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 11 bytes: 'AT+CSDH=1\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CSDH=1\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 11 bytes: 'AT+CSDH=1\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1582
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CSDH=1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1583
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CSDH=1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1584
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT+CSDH=1' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 11 bytes: 'AT+CSNS=0\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CSNS=0\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:58 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 11 bytes: 'AT+CSNS=0\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1591
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:58 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CSNS=0' => ['OK']
May  1 16:47:58 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1592
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CSNS=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1593
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT+CSNS=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 11 bytes: 'AT+CMGF=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CMGF=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 11 bytes: 'AT+CMGF=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1600
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CMGF=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1601
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CMGF=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1602
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT+CMGF=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 11 bytes: 'AT+CLIP=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CLIP=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 11 bytes: 'AT+CLIP=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1609
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CLIP=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1610
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CLIP=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1611
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT+CLIP=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 11 bytes: 'AT+COLP=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+COLP=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 11 bytes: 'AT+COLP=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1618
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+COLP=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1619
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+COLP=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1620
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT+COLP=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 11 bytes: 'AT+CCWA=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CCWA=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 11 bytes: 'AT+CCWA=0\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1627
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CCWA=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1628
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CCWA=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1629
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT+CCWA=0' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 11 bytes: 'AT%CUNS=2\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT%CUNS=2\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:47:59 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: sending 11 bytes: 'AT%CUNS=2\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1636
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:47:59 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT%CUNS=2' => ['OK']
May  1 16:47:59 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1637
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT%CUNS=2' => ['OK']
May  1 16:48:00 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToRead: watch timeout = 1638
May  1 16:48:00 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: COMPLETED 'AT%CUNS=2' => ['OK']
May  1 16:48:00 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CLIP=1\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <CallChannel via /dev/pts/6>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1645
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CLIP=1' => ['OK']
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+COLP=0\r\n'
May  1 16:48:00 calvino ousaged  INFO     Enabled GSM in 15.3 seconds
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1648
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+COLP=0' => ['OK']
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CCWA=1\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1651
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CCWA=1' => ['OK']
May  1 16:48:00 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 10 bytes: 'AT+CPIN?\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 13 bytes: 'AT+CSSN=1,1\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1656
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CSSN=1,1' => ['OK']
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CTZU=1\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1659
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CTZU=1' => ['OK']
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CTZR=1\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1662
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CTZR=1' => ['OK']
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CREG=2\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1665
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CREG=2' => ['OK']
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CAOC=2\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1668
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:00 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CAOC=2' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 15 bytes: 'AT+CGEREP=2,1\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1671
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CGEREP=2,1' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 12 bytes: 'AT+CGREG=2\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1674
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CGREG=2' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 10 bytes: 'AT%CPI=3\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1677
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT%CPI=3' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 17 bytes: 'AT%CSCN=1,2,1,2\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1680
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT%CSCN=1,2,1,2' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 10 bytes: 'AT%CSQ=1\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1683
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 18 bytes: '\r\n%CSQ: 1 \r\n\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT%CSQ=1' => ['%CSQ: 1 ', 'OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT%CPRI=1\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1686
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT%CPRI=1' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT%CNIV=1\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1689
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT%CNIV=1' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 12 bytes: 'AT%CSTAT=1\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1692
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT%CSTAT=1' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 13 bytes: 'AT@ST="-26"\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1695
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT@ST="-26"' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 12 bytes: 'AT%SLEEP=4\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1698
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 16 bytes: '\r\nEXT: I\r\n\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT%SLEEP=4' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 10 bytes: 'AT%N0187\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1701
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 57 bytes: '\r\nEXT: I\r\nBoth AEC and Noise reduction are active\r\n\r\nOK\r\n'
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT%N0187' => ['OK']
May  1 16:48:01 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:02 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:02 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 16 bytes: '%CSTAT: PHB, 0\r\n'
May  1 16:48:02 calvino ogsmd    INFO     subsystem PHB readyness now False
May  1 16:48:02 calvino ogsmd.device INFO     sim ready status False
May  1 16:48:02 calvino ogsmd    INFO     full readyness now False
May  1 16:48:05 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:05 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 16 bytes: '%CSTAT: PHB, 0\r\n'
May  1 16:48:05 calvino ogsmd    INFO     subsystem PHB readyness now False
May  1 16:48:05 calvino ogsmd    INFO     full readyness now False
May  1 16:48:05 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:05 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 16 bytes: '%CSTAT: PHB, 0\r\n'
May  1 16:48:05 calvino ogsmd    INFO     subsystem PHB readyness now False
May  1 16:48:05 calvino ogsmd    INFO     full readyness now False
May  1 16:48:06 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1655
May  1 16:48:06 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 16 bytes: '\r\n+CPIN: READY\r\n'
May  1 16:48:06 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:06 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 16 bytes: '%CSTAT: PHB, 0\r\n'
May  1 16:48:06 calvino ogsmd    INFO     subsystem PHB readyness now False
May  1 16:48:06 calvino ogsmd    INFO     full readyness now False
May  1 16:48:06 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1704
May  1 16:48:06 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:06 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CPIN?' => ['+CPIN: READY', 'OK']
May  1 16:48:06 calvino ogsmd.device INFO     auth status changed to READY
May  1 16:48:06 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:06 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 11 bytes: 'AT+CFUN=1\r\n'
May  1 16:48:10 calvino odeviced.idlenotifier INFO     odeviced.idlenotifier state change to idle
May  1 16:48:10 calvino oeventsd.action INFO     DebugAction : dbus trigger test
May  1 16:48:10 calvino oeventsd.fso_triggers INFO     Receive IdleState, status = idle
May  1 16:48:11 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:11 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 32 bytes: '%CSTAT: PHB, 0\r\n%CSTAT: PHB, 0\r\n'
May  1 16:48:11 calvino ogsmd    INFO     subsystem PHB readyness now False
May  1 16:48:11 calvino ogsmd    INFO     full readyness now False
May  1 16:48:11 calvino ogsmd    INFO     subsystem PHB readyness now False
May  1 16:48:11 calvino ogsmd    INFO     full readyness now False
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1710
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CFUN=1' => ['OK']
May  1 16:48:12 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:12 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 16 bytes: '%CSTAT: PHB, 0\r\n'
May  1 16:48:12 calvino ogsmd    INFO     subsystem PHB readyness now False
May  1 16:48:12 calvino ogsmd    INFO     full readyness now False
May  1 16:48:12 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:12 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 13 bytes: 'AT+CLVL=255\r\n'
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 10 bytes: 'AT+CPIN?\r\n'
May  1 16:48:12 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1714
May  1 16:48:12 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:12 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CLVL=255' => ['OK']
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1715
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 22 bytes: '\r\n+CPIN: READY\r\n\r\nOK\r\n'
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CPIN?' => ['+CPIN: READY', 'OK']
May  1 16:48:12 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:12 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 13 bytes: 'AT+COPS=0,0\r\n'
May  1 16:48:12 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:12 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 12 bytes: '\r\n+CREG: 2\r\n'
May  1 16:48:15 calvino kernel: [25863.495000] fbcon_event_notify action=9, data=c667be10
May  1 16:48:15 calvino kernel: [25863.495000] jbt6k74 spi2.0: **** jbt6k74 vsync suspend
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CSMS=1\r\n'
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1723
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 19 bytes: '\r\n+CMS ERROR: 314\r\n'
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CSMS=1' => ['+CMS ERROR: 314']
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 19 bytes: 'AT+CNMI=2,1,2,1,1\r\n'
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1726
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 19 bytes: '\r\n+CMS ERROR: 314\r\n'
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CNMI=2,1,2,1,1' => ['+CMS ERROR: 314']
May  1 16:48:16 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:48:17 calvino kernel: [25865.880000] fbcon_event_notify action=12, data=c667bdc8
May  1 16:48:17 calvino kernel: [25865.880000] jbt6k74 spi2.0: **** jbt6k74 unblank
May  1 16:48:17 calvino kernel: [25865.960000] fbcon_event_notify action=9, data=c667be10
May  1 16:48:17 calvino kernel: [25865.960000] jbt6k74 spi2.0: **** jbt6k74 unblank
May  1 16:48:17 calvino odeviced.idlenotifier INFO     odeviced.idlenotifier state change to busy
May  1 16:48:17 calvino oeventsd.action INFO     DebugAction : dbus trigger test
May  1 16:48:17 calvino oeventsd.fso_triggers INFO     Receive IdleState, status = busy
May  1 16:48:17 calvino oeventsd.action INFO     DebugAction : Hello This is a test
May  1 16:48:19 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1721
May  1 16:48:19 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 6 bytes: '\r\nOK\r\n'
May  1 16:48:19 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+COPS=0,0' => ['OK']
May  1 16:48:19 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:19 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 46 bytes: '\r\n+CREG: 1,"1449","A50C"\r\n\r\n%CSQ:  22, 99, 2\r\n'
May  1 16:48:19 calvino ogsmd.device INFO     org.freesmartphone.GSM.Network.SignalStrength: 90
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 8 bytes: 'AT+CSQ\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1731
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 22 bytes: '\r\n+CSQ: 22,99 \r\n\r\nOK\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CSQ' => ['+CSQ: 22,99 ', 'OK']
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 8 bytes: 'AT+CSQ\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1734
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 22 bytes: '\r\n+CSQ: 22,99 \r\n\r\nOK\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CSQ' => ['+CSQ: 22,99 ', 'OK']
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 8 bytes: 'AT+CSQ\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1737
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 22 bytes: '\r\n+CSQ: 22,99 \r\n\r\nOK\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CSQ' => ['+CSQ: 22,99 ', 'OK']
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 10 bytes: 'AT+CREG?\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1740
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 20 bytes: '\r\n+CREG: 0,1\r\n\r\nOK\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CREG?' => ['+CREG: 0,1', 'OK']
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 10 bytes: 'AT+CREG?\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1743
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 20 bytes: '\r\n+CREG: 0,1\r\n\r\nOK\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CREG?' => ['+CREG: 0,1', 'OK']
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 10 bytes: 'AT+CREG?\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1746
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 20 bytes: '\r\n+CREG: 0,1\r\n\r\nOK\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CREG?' => ['+CREG: 0,1', 'OK']
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 26 bytes: 'AT+CREG=2;+CREG?;+CREG=0\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1749
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 34 bytes: '\r\n+CREG: 2,1,"1449","A50C"\r\n\r\nOK\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CREG=2;+CREG?;+CREG=0' => ['+CREG: 2,1,"1449","A50C"', 'OK']
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 26 bytes: 'AT+CREG=2;+CREG?;+CREG=0\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1752
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 34 bytes: '\r\n+CREG: 2,1,"1449","A50C"\r\n\r\nOK\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CREG=2;+CREG?;+CREG=0' => ['+CREG: 2,1,"1449","A50C"', 'OK']
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 26 bytes: 'AT+CREG=2;+CREG?;+CREG=0\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1755
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 34 bytes: '\r\n+CREG: 2,1,"1449","A50C"\r\n\r\nOK\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+CREG=2;+CREG?;+CREG=0' => ['+CREG: 2,1,"1449","A50C"', 'OK']
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 37 bytes: 'AT+COPS=3,0;+COPS?;+COPS=3,2;+COPS?\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1758
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 25 bytes: '\r\n+COPS: 0,0,"T-Mobile"\r\n'
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1759
May  1 16:48:20 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 28 bytes: '\r\n+COPS: 0,2,"31026"\r\n\r\nOK\r\n'
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+COPS=3,0;+COPS?;+COPS=3,2;+COPS?' => ['+COPS: 0,0,"T-Mobile"', '+COPS: 0,2,"31026"', 'OK']
May  1 16:48:21 calvino ogsmd.device INFO     org.freesmartphone.GSM.Network.Status: {'strength': 90, 'cid': u'A50C', 'registration': 'home', 'lac': u'1449', 'act': 'GSM', 'code': u'31026', 'mode': 'automatic', 'provider': u'T-Mobile'}
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 37 bytes: 'AT+COPS=3,0;+COPS?;+COPS=3,2;+COPS?\r\n'
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1762
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 53 bytes: '\r\n+COPS: 0,0,"T-Mobile"\r\n\r\n+COPS: 0,2,"31026"\r\n\r\nOK\r\n'
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+COPS=3,0;+COPS?;+COPS=3,2;+COPS?' => ['+COPS: 0,0,"T-Mobile"', '+COPS: 0,2,"31026"', 'OK']
May  1 16:48:21 calvino ogsmd.device INFO     org.freesmartphone.GSM.Network.Status: {'strength': 90, 'cid': u'A50C', 'registration': 'home', 'lac': u'1449', 'act': 'GSM', 'code': u'31026', 'mode': 'automatic', 'provider': u'T-Mobile'}
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: sending 37 bytes: 'AT+COPS=3,0;+COPS?;+COPS=3,2;+COPS?\r\n'
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToRead: watch timeout = 1765
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: got 53 bytes: '\r\n+COPS: 0,0,"T-Mobile"\r\n\r\n+COPS: 0,2,"31026"\r\n\r\nOK\r\n'
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: COMPLETED 'AT+COPS=3,0;+COPS?;+COPS=3,2;+COPS?' => ['+COPS: 0,0,"T-Mobile"', '+COPS: 0,2,"31026"', 'OK']
May  1 16:48:21 calvino ogsmd.channel DEBUG    <MiscChannel via /dev/pts/1>: _readyToSend: watch timeout = None
May  1 16:48:21 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:21 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 32 bytes: '%CSTAT: PHB, 0\r\n%CSTAT: SMS, 1\r\n'
May  1 16:48:21 calvino ogsmd    INFO     subsystem PHB readyness now False
May  1 16:48:21 calvino ogsmd    INFO     full readyness now False
May  1 16:48:21 calvino ogsmd    INFO     subsystem SMS readyness now True
May  1 16:48:22 calvino ogsmd    INFO     full readyness now False
May  1 16:48:22 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:22 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 14 bytes: '\r\n+CTZV: 105\r\n'
May  1 16:48:22 calvino ogsmd.device INFO     org.freesmartphone.GSM.Network.TimeZoneReport: %d
May  1 16:48:22 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:22 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 14 bytes: '\r\n%CPRI: 1,2\r\n'
May  1 16:48:22 calvino ogsmd.device INFO     org.freesmartphone.GSM.Network.CypherStatus: enabled: unknown
May  1 16:48:27 calvino odeviced.idlenotifier INFO     odeviced.idlenotifier state change to idle
May  1 16:48:27 calvino oeventsd.action INFO     DebugAction : dbus trigger test
May  1 16:48:27 calvino oeventsd.fso_triggers INFO     Receive IdleState, status = idle
May  1 16:48:34 calvino odeviced.idlenotifier INFO     odeviced.idlenotifier state change to busy
May  1 16:48:34 calvino oeventsd.action INFO     DebugAction : dbus trigger test
May  1 16:48:34 calvino oeventsd.fso_triggers INFO     Receive IdleState, status = busy
May  1 16:48:34 calvino oeventsd.action INFO     DebugAction : Hello This is a test
May  1 16:48:50 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:48:50 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 17 bytes: '%CSTAT: EONS, 1\r\n'
May  1 16:48:50 calvino ogsmd    INFO     full readyness now False
May  1 16:48:51 calvino odeviced.idlenotifier INFO     odeviced.idlenotifier state change to idle
May  1 16:48:51 calvino oeventsd.action INFO     DebugAction : dbus trigger test
May  1 16:48:51 calvino oeventsd.fso_triggers INFO     Receive IdleState, status = idle
May  1 16:49:11 calvino kernel: [25920.990000] fbcon_event_notify action=9, data=c667be10
May  1 16:49:11 calvino kernel: [25920.990000] jbt6k74 spi2.0: **** jbt6k74 vsync suspend
May  1 16:49:11 calvino odeviced.idlenotifier INFO     odeviced.idlenotifier state change to idle_dim
May  1 16:49:11 calvino oeventsd.action INFO     DebugAction : dbus trigger test
May  1 16:49:11 calvino oeventsd.fso_triggers INFO     Receive IdleState, status = idle_dim
May  1 16:49:16 calvino kernel: [25926.150000] fbcon_event_notify action=9, data=c667be10
May  1 16:49:16 calvino kernel: [25926.150000] jbt6k74 spi2.0: **** jbt6k74 hsync suspend
May  1 16:49:21 calvino kernel: [25931.310000] fbcon_event_notify action=9, data=c667be10
May  1 16:49:21 calvino kernel: [25931.310000] jbt6k74 spi2.0: **** jbt6k74 powerdown
May  1 16:49:22 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:49:22 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 16 bytes: '%CSTAT: PHB, 1\r\n'
May  1 16:49:22 calvino ogsmd    INFO     subsystem PHB readyness now True
May  1 16:49:22 calvino ogsmd.device INFO     sim ready status True
May  1 16:49:22 calvino ogsmd    INFO     full readyness now True
May  1 16:49:22 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = None
May  1 16:49:22 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 16 bytes: '%CSTAT: RDY, 1\r\n'
May  1 16:49:22 calvino ogsmd    INFO     full readyness now True
May  1 16:49:23 calvino odeviced.idlenotifier INFO     odeviced.idlenotifier state change to idle_prelock
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 11 bytes: 'AT+CSMS=1\r\n'
May  1 16:49:23 calvino oeventsd.action INFO     DebugAction : dbus trigger test
May  1 16:49:23 calvino oeventsd.fso_triggers INFO     Receive IdleState, status = idle_prelock
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1772
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 22 bytes: '\r\n+CSMS: 1,1,1\r\n\r\nOK\r\n'
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CSMS=1' => ['+CSMS: 1,1,1', 'OK']
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: sending 19 bytes: 'AT+CNMI=2,1,2,1,1\r\n'
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToRead: watch timeout = 1775
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: got 6 bytes: '\r\nOK\r\n'
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: COMPLETED 'AT+CNMI=2,1,2,1,1' => ['OK']
May  1 16:49:23 calvino ogsmd.channel DEBUG    <UnsolicitedResponseChannel via /dev/pts/2>: _readyToSend: watch timeout = None
May  1 16:49:25 calvino odeviced.idlenotifier INFO     odeviced.idlenotifier state change to lock
May  1 16:49:25 calvino oeventsd.action INFO     DebugAction : dbus trigger test
May  1 16:49:25 calvino oeventsd.fso_triggers INFO     Receive IdleState, status = lock