View Single Post
fnordianslip's Avatar
Posts: 670 | Thanked: 359 times | Joined on May 2007
#18
follow the instructions in comment 5 of bug #1203
Thanks. That's helped immensely. I can now see where my connection attempts are failing. Here's an extract from my iBook's PPP log, showing a failed connection attempt (which happens enough to be annoying) followed by a successful connection attempt.

Sun Apr 22 23:49:09 2007 : Sony Ericsson 3G CID1
Sun Apr 22 23:49:09 2007 : CCLWrite : AT\13
Sun Apr 22 23:49:09 2007 : CCLMatched : OK\13\10
Sun Apr 22 23:49:09 2007 : CCLWrite : AT+CGMI\13
Sun Apr 22 23:49:09 2007 : CCLMatched : Ericsson
Sun Apr 22 23:49:09 2007 : CCLWrite : AT&FE0S0=0\13
Sun Apr 22 23:49:09 2007 : CCLMatched : OK\13\10
Sun Apr 22 23:49:09 2007 : CCLWrite : AT+CGDCONT=1,"IP","three.co.uk"\13
Sun Apr 22 23:49:10 2007 : CCLMatched : ERROR\13\10
Sun Apr 22 23:49:10 2007 : Connect script failed
Sun Apr 22 23:49:26 2007 : Sony Ericsson 3G CID1
Sun Apr 22 23:49:26 2007 : CCLWrite : AT\13
Sun Apr 22 23:49:26 2007 : CCLMatched : OK\13\10
Sun Apr 22 23:49:26 2007 : CCLWrite : AT+CGMI\13
Sun Apr 22 23:49:26 2007 : CCLMatched : Ericsson
Sun Apr 22 23:49:26 2007 : CCLWrite : AT&FE0S0=0\13
Sun Apr 22 23:49:26 2007 : CCLMatched : OK\13\10
Sun Apr 22 23:49:26 2007 : CCLWrite : AT+CGDCONT=1,"IP","three.co.uk"\13
Sun Apr 22 23:49:26 2007 : CCLMatched : OK\13\10
Sun Apr 22 23:49:26 2007 : Making network connection
Sun Apr 22 23:49:26 2007 : CCLWrite : ATD*99***1#\13
Sun Apr 22 23:49:27 2007 : CCLMatched : CONNECT
Sun Apr 22 23:49:32 2007 : Serial connection established.
Sun Apr 22 23:49:32 2007 : using link 0
Sun Apr 22 23:49:32 2007 : Using interface ppp0
Sun Apr 22 23:49:32 2007 : Connect: ppp0 <--> /dev/cu.Bluetooth-Modem
Sun Apr 22 23:49:33 2007 : sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x30e02c9a> <pcomp> <accomp>]
Sun Apr 22 23:49:33 2007 : rcvd [LCP ConfReq id=0x3 <auth pap> <accomp> <pcomp> <asyncmap 0x0> <magic 0x32abcf28>]
Sun Apr 22 23:49:33 2007 : lcp_reqci: returning CONFACK.
Sun Apr 22 23:49:33 2007 : sent [LCP ConfAck id=0x3 <auth pap> <accomp> <pcomp> <asyncmap 0x0> <magic 0x32abcf28>]
Sun Apr 22 23:49:33 2007 : rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x30e02c9a> <pcomp> <accomp>]
Sun Apr 22 23:49:33 2007 : sent [PAP AuthReq id=0x1 user="guest" password=<hidden>]
Sun Apr 22 23:49:33 2007 : rcvd [PAP AuthAck id=0x1 "Congratulations!"]
Sun Apr 22 23:49:33 2007 : Remote message: Congratulations!
Sun Apr 22 23:49:33 2007 : PAP authentication succeeded
Sun Apr 22 23:49:33 2007 : sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Sun Apr 22 23:49:36 2007 : sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Sun Apr 22 23:49:37 2007 : rcvd [IPCP ConfReq id=0x1]
Sun Apr 22 23:49:37 2007 : ipcp: returning Configure-NAK
Sun Apr 22 23:49:37 2007 : sent [IPCP ConfNak id=0x1 <addr 0.0.0.0>]
Sun Apr 22 23:49:37 2007 : rcvd [IPCP ConfNak id=0x1 <addr 10.35.218.59> <ms-dns1 172.31.140.69> <ms-dns3 172.30.140.69>]
Sun Apr 22 23:49:37 2007 : sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 10.35.218.59> <ms-dns1 172.31.140.69> <ms-dns3 172.30.140.69>]
Sun Apr 22 23:49:37 2007 : rcvd [IPCP ConfReq id=0x2]
Sun Apr 22 23:49:37 2007 : ipcp: returning Configure-ACK
Sun Apr 22 23:49:37 2007 : sent [IPCP ConfAck id=0x2]
Sun Apr 22 23:49:37 2007 : rcvd [IPCP ConfAck id=0x2 <compress VJ 0f 01> <addr 10.35.218.59> <ms-dns1 172.31.140.69> <ms-dns3 172.30.140.69>]
Sun Apr 22 23:49:37 2007 : ipcp: up
Sun Apr 22 23:49:37 2007 : Could not determine remote IP address: defaulting to 10.64.64.64
Sun Apr 22 23:49:37 2007 : local IP address 10.35.218.59
Sun Apr 22 23:49:37 2007 : remote IP address 10.64.64.64
Sun Apr 22 23:49:37 2007 : primary DNS address 172.31.140.69
Sun Apr 22 23:49:37 2007 : secondary DNS address 172.30.140.69
Mon Apr 23 00:26:30 2007 : Hangup (SIGHUP)
Mon Apr 23 00:26:30 2007 : ipcp: down
Mon Apr 23 00:26:30 2007 : sent [LCP TermReq id=0x2 "User request"]
Mon Apr 23 00:26:30 2007 : rcvd [LCP TermAck id=0x2]
Mon Apr 23 00:26:30 2007 : Connection terminated.
Mon Apr 23 00:26:30 2007 : Connect time 37.0 minutes.
Mon Apr 23 00:26:30 2007 : Sent 127143 bytes, received 297786 bytes.
Mon Apr 23 00:26:31 2007 : Hangup (SIGHUP)
Mon Apr 23 00:26:31 2007 : Modem hangup
Here is a connection attempt on the n800. Note that it fails the same way as the iBook does, but the n800 never connects successfully.


May 9 19:22:49 Nokia-N800-10 btsdp[1255]: DUN, channel 2, ttl 0, "Dial-up Networking"
May 9 19:22:50 Nokia-N800-10 btcond[861]: btsdp_notify()
May 9 19:22:50 Nokia-N800-10 btcond[861]: handle_btsdp_reply()
May 9 19:22:50 Nokia-N800-10 btcond[861]: 00:18:13:9A:77:E6: adding DUN, channel 2, ttl 0, "Dial-up Networking"
May 9 19:22:50 Nokia-N800-10 btcond[861]: connect_service("00:18:13:9A:77:E6", "DUN", ":1.15", auth, noencrypt, "any")
May 9 19:22:50 Nokia-N800-10 btcond[861]: Connect in progress
May 9 19:22:50 Nokia-N800-10 btcond[861]: process_update_queue()
May 9 19:22:50 Nokia-N800-10 iap_conndlg 1.3.48[1032]: NameownerChanged(com.nokia.btsdp, :1.60, )
May 9 19:22:50 Nokia-N800-10 iap_conndlg 1.3.48[1032]: NameownerChanged(:1.60, :1.60, )
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: Service 'com.nokia.btsdp' no longer exists.
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: Base service ':1.60' no longer exists.
May 9 19:22:50 Nokia-N800-10 btsdp[1255]: Exiting.
May 9 19:22:50 Nokia-N800-10 hcid[771]: link_key_request (sba=00:19:4F:A4:CC0, dba=00:18:13:9A:77:E6)
May 9 19:22:50 Nokia-N800-10 btcond[861]: sock_io_cb: connected
May 9 19:22:50 Nokia-N800-10 ke_recv[896]: handle_kevent:327: i|m|p: org.kernel.kevent|add|/org/kernel/class/tty/rfcomm0
May 9 19:22:50 Nokia-N800-10 btcond[861]: connect_cb: (00:18:13:9A:77:E6, DUN): connected
May 9 19:22:50 Nokia-N800-10 btcond[861]: add_name_listener(:1.15)
May 9 19:22:50 Nokia-N800-10 btcond[861]: sending rfcomm_status("00:18:13:9A:77:E6", "DUN", "connected") signal
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: Using RFCOMM device: /dev/rfcomm0
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Open: '/dev/rfcomm0'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Sending: 'AT&F'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-CB: IN
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Received: 'AT&F'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Received: 'OK'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Sending: 'AT+GCAP'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-CB: IN
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-CB: IN
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Received: 'AT+GCAP'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Received: '+GCAP: +CGSM, +DS'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-CB: IN
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Received: 'OK'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Sending: 'AT+CMEE=1'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-CB: IN
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-CB: IN
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Received: 'AT+CMEE=1'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Received: 'OK'
May 9 19:22:50 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Sending: 'AT+CGDCONT=1,"ip","three.co.uk"'
May 9 19:22:51 Nokia-N800-10 kernel: [ 1517.526824] EAC mode: play disabled, rec disabled
May 9 19:22:51 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-CB: IN
May 9 19:22:51 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-CB: IN
May 9 19:22:51 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Received: 'AT+CGDCONT=1,"ip","three.co.uk"'
May 9 19:22:51 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Received: 'ERROR'
May 9 19:22:51 Nokia-N800-10 icd 1.1.26[916]: [3] Error: AT dialogue failed (com.nokia.icd.error.system_error)
May 9 19:22:51 Nokia-N800-10 icd 1.1.26[916]: [3] State changed from CONNECTING to DISCONNECTING
May 9 19:22:51 Nokia-N800-10 icd 1.1.26[916]: [3] Disconnect: killing IAP
May 9 19:22:51 Nokia-N800-10 icd 1.1.26[916]: [0x26320] AT-Close
May 9 19:22:51 Nokia-N800-10 btcond[861]: Received rfcomm_disconnect
May 9 19:22:51 Nokia-N800-10 btcond[861]: disconnect_service("00:18:13:9A:77:E6", "DUN")
May 9 19:22:51 Nokia-N800-10 btcond[861]: sending rfcomm_status("DUN", "00:18:13:9A:77:E6", "disconnected") signal
May 9 19:22:51 Nokia-N800-10 btcond[861]: remove_name_listener(:1.15)
May 9 19:22:51 Nokia-N800-10 maemo_af_desktop[1013]: common_inetstate: connection '3' with type 'DUN_GSM_PS' and status 'DISCONNECTING' (3) and reason 'com.nokia.icd.error.system_error'
May 9 19:22:51 Nokia-N800-10 icd 1.1.26[916]: Disconnected from RFCOMM device: /dev/rfcomm0
May 9 19:22:51 Nokia-N800-10 maemo_af_desktop[1013]: connecting contains 1 elements, connected 0
May 9 19:22:51 Nokia-N800-10 icd 1.1.26[916]: [3] State changed from DISCONNECTING to IDLE
May 9 19:22:51 Nokia-N800-10 maemo_af_desktop[1013]: closing '3'

I'm not sure if the problems I'm having are with the Sony Erricsson K800i being flakey at DUN and marginally palatable to the iBook, but not at all to the n800, or something else. As an aside, and possibly more on topic, I've found 3's 3G/UMTS service to be be pretty flakey at replying to ConfReqs, often leaving me stranded with a link layer connection but no IP address. All in all, quite unsatisfactory, but I'd like to get the n800 connecting at least as well as the iBook, which is better than nothing.

I wouldn't automatically pin this on the phone, as I had similar issues with GPRS on a Z600 with my iBook before (and a very sucky data service from O2). Any idea's what might be going wrong?