All of lore.kernel.org
 help / color / mirror / Atom feed
* Unable to establish a complete PPP link on Sagem Hilo GPRS modem
@ 2012-08-20  7:55 Schroeter Nicolas
  2012-08-20 13:29 ` Denis Kenzior
  0 siblings, 1 reply; 3+ messages in thread
From: Schroeter Nicolas @ 2012-08-20  7:55 UTC (permalink / raw)
  To: ofono

[-- Attachment #1: Type: text/plain, Size: 10692 bytes --]

Hi,

I am developing a plugin for the Sagem Hilo GPRS modem. I use the ofono version 1.10.
When I activate the GPRS context, I never get a complete established PPP link. The PPP debug is:


Jan  2 16:24:36 109656587698 daemon.info ofonod[600]: Aux: > AT+CGATT=1\r
Jan  2 16:24:39 109656587698 daemon.info ofonod[600]: Aux: < \r\nOK\r\n\r\n+CGREG:
Jan  2 16:24:39 109656587698 daemon.info ofonod[600]: Aux: <  1,"00CA","1
Jan  2 16:24:39 109656587698 daemon.info ofonod[600]: Aux: < 7A6"\r\n\r\n+CIEV:
Jan  2 16:24:39 109656587698 daemon.debug ofonod[600]: src/gprs.c:gprs_attach_callback() /hilo_0 error = 0
Jan  2 16:24:39 109656587698 daemon.debug ofonod[600]: src/gprs.c:ofono_gprs_status_notify() /hilo_0 status 1
Jan  2 16:24:39 109656587698 daemon.info ofonod[600]: Aux: > AT+COPS=3,0\r
Jan  2 16:24:39 109656587698 daemon.info ofonod[600]: Aux: < 2,1 \r\n\r\n+CIEV: 1,2\r\n
Jan  2 16:24:39 109656587698 daemon.debug ofonod[600]: src/network.c:ofono_netreg_strength_notify() strength 25
Jan  2 16:24:40 109656587698 daemon.info ofonod[600]: Aux: < \r\nOK\r\n
Jan  2 16:24:40 109656587698 daemon.info ofonod[600]: Aux: > AT+COPS?\r
Jan  2 16:24:40 109656587698 daemon.info ofonod[600]: Aux: < \r\n+COPS: 0,0,"SWISS"\r\n\r\nOK\r\n
Jan  2 16:24:40 109656587698 daemon.debug ofonod[600]: drivers/atmodem/network-registration.c:cops_cb() cops_cb: SWISS, 228 01 0
Jan  2 16:24:40 109656587698 daemon.debug ofonod[600]: src/network.c:current_operator_callback() 0x382bf0, (nil)
Jan  2 16:24:40 109656587698 daemon.debug ofonod[600]: src/gprs.c:netreg_status_changed() 1
Jan  2 16:24:40 109656587698 daemon.info ofonod[600]: Aux: > AT+CGREG?\rJan  2 16:24:40 109656587698 daemon.info ofonod[600]: Aux: < \r\n+CGREG: 2,1,"00CA","17A6"\r\n\r\nOK\r\n
Jan  2 16:24:40 109656587698 daemon.debug ofonod[600]: src/gprs.c:registration_status_cb() /hilo_0 error 0 status 1
Jan  2 16:24:40 109656587698 daemon.debug ofonod[600]: src/gprs.c:ofono_gprs_status_notify() /hilo_0 status 1
Jan  2 16:24:40 109656587698 daemon.info ofonod[600]: Aux: < \r\n+CIEV: 1,3\r\n
Jan  2 16:25:14 109656587698 daemon.debug ofonod[600]: drivers/atmodem/gprs-context.c:at_gprs_activate_primary() cid 1
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: Aux: > AT+CGDCONT=1,"IP","gprs.swisscom.ch","",0,0\r
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: Aux: < \r\nOK\r\n
Jan  2 16:25:14 109656587698 daemon.debug ofonod[600]: drivers/atmodem/gprs-context.c:at_cgdcont_cb() ok 1
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: Aux: > AT&FE0Q0V1\r
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: Aux: < \r\nOK\r\n

Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: Aux: > ATD*99***1#\r
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: Aux: < \r\nCONNECT\r\n
Jan  2 16:25:14 109656587698 daemon.debug ofonod[600]: drivers/atmodem/gprs-context.c:at_cgdata_cb() ok 1
Jan  2 16:25:14 109656587698 daemon.debug ofonod[600]: drivers/atmodem/gprs-context.c:setup_ppp()
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 0:INITIAL
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 0 (Up), action: 2, new_state: 2 (CLOSED)
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 2:CLOSED
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 2 (Open), action: 1026, new_state: 6 (REQSENT)
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_initialize_restart_count: current state 2:CLOSED
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_send_configure_request: current state 2:CLOSED

Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: gatchat/gatppp.c:ppp_enter_phase() 1
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_process_configure_ack: current state 6:REQSENT
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 6:REQSENT
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 8 (RCA), action: 27, new_state: 7 (ACKRCVD)
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_initialize_restart_count: current state 6:REQSENT

Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_process_configure_request: current state 7:ACKRCVD
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 7:ACKRCVD
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 7 (RCR-), action: 4007, new_state: 7 (ACKRCVD)

Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_send_configure_nak: current state 7:ACKRCVD
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_process_configure_request: current state 7:ACKRCVD
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 7:ACKRCVD
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 6 (RCR+), action: 2109, new_state: 9 (OPENED)

Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_send_configure_ack: current state 7:ACKRCVD
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: gatchat/gatppp.c:ppp_enter_phase() 2
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: gatchat/gatppp.c:ppp_enter_phase() 3
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 0:INITIAL
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 2 (Open), action: 401, new_state: 1 (STARTING)

Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 1:STARTING
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 0 (Up), action: 1026, new_state: 6 (REQSENT)
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_initialize_restart_count: current state 1:STARTING
Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_send_configure_request: current state 1:STARTING
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_timeout: current state 6:REQSENT

Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 6:REQSENT


Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 4 (TO+), action: 1006, new_state: 6 (REQSENT)
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_send_configure_request: current state 6:REQSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_process_configure_request: current state 6:REQSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 6:REQSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 6 (RCR+), action: 2008, new_state: 8 (ACKSENT)
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_send_configure_ack: current state 6:REQSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_process_configure_reject: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 9 (RCN), action: 1028, new_state: 8 (ACKSENT)
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_initialize_restart_count: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_send_configure_request: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_process_configure_nak: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 9 (RCN), action: 1028, new_state: 8 (ACKSENT)
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_initialize_restart_count: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_send_configure_request: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_process_configure_ack: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 8 (RCA), action: 129, new_state: 9 (OPENED)
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_initialize_restart_count: current state 8:ACKSENT
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 9:OPENED
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 3 (Close), action: 8224, new_state: 4 (CLOSING)
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_initialize_restart_count: current state 9:OPENED
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_send_terminate_request: current state 9:OPENED
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 9:OPENED
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 1 (Down), action: 201, new_state: 1 (STARTING)
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: gatchat/gatppp.c:ppp_enter_phase() 5
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_process_terminate_ack: current state 4:CLOSING
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 4:CLOSING
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 11 (RTA), action: 802, new_state: 2 (CLOSED)
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_this_layer_finished: current state 2:CLOSED
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: gatchat/gatppp.c:ppp_enter_phase() 0
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: gatchat/gatppp.c:ppp_dead()
Jan  2 16:25:18 109656587698 daemon.debug ofonod[600]: drivers/atmodem/gprs-context.c:ppp_disconnect()
Jan  2 16:25:18 109656587698 daemon.debug ofonod[600]: src/gprs.c:pri_activate_callback() 0x37f040
Jan  2 16:25:18 109656587698 daemon.debug ofonod[600]: src/gprs.c:pri_activate_callback() Activating context failed with error: Unknown error type
Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: Aux: < \r\n+CGEV: NW DETACH\r\n
Jan  2 16:25:18 109656587698 daemon.debug ofonod[600]: src/gprs.c:ofono_gprs_detached_notify() /hilo_0


Could please anybody here give me some advice how to solve the problem?

best regards
Nicolas



^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: Unable to establish a complete PPP link on Sagem Hilo GPRS modem
  2012-08-20  7:55 Unable to establish a complete PPP link on Sagem Hilo GPRS modem Schroeter Nicolas
@ 2012-08-20 13:29 ` Denis Kenzior
  2012-08-20 16:30   ` Schroeter Nicolas
  0 siblings, 1 reply; 3+ messages in thread
From: Denis Kenzior @ 2012-08-20 13:29 UTC (permalink / raw)
  To: ofono

[-- Attachment #1: Type: text/plain, Size: 6384 bytes --]

Hi Nicolas,

<snip>

> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: Aux:>  ATD*99***1#\r
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: Aux:<  \r\nCONNECT\r\n
> Jan  2 16:25:14 109656587698 daemon.debug ofonod[600]: drivers/atmodem/gprs-context.c:at_cgdata_cb() ok 1
> Jan  2 16:25:14 109656587698 daemon.debug ofonod[600]: drivers/atmodem/gprs-context.c:setup_ppp()
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 0:INITIAL
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 0 (Up), action: 2, new_state: 2 (CLOSED)
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 2:CLOSED
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 2 (Open), action: 1026, new_state: 6 (REQSENT)
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_initialize_restart_count: current state 2:CLOSED
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_send_configure_request: current state 2:CLOSED
>
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: gatchat/gatppp.c:ppp_enter_phase() 1
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_process_configure_ack: current state 6:REQSENT
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 6:REQSENT
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 8 (RCA), action: 27, new_state: 7 (ACKRCVD)
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_initialize_restart_count: current state 6:REQSENT
>
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_process_configure_request: current state 7:ACKRCVD
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 7:ACKRCVD
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 7 (RCR-), action: 4007, new_state: 7 (ACKRCVD)
>
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_send_configure_nak: current state 7:ACKRCVD
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_process_configure_request: current state 7:ACKRCVD
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 7:ACKRCVD
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 6 (RCR+), action: 2109, new_state: 9 (OPENED)
>
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_send_configure_ack: current state 7:ACKRCVD
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: gatchat/gatppp.c:ppp_enter_phase() 2
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: gatchat/gatppp.c:ppp_enter_phase() 3
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 0:INITIAL
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 2 (Open), action: 401, new_state: 1 (STARTING)
>
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 1:STARTING
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 0 (Up), action: 1026, new_state: 6 (REQSENT)
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_initialize_restart_count: current state 1:STARTING
> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_send_configure_request: current state 1:STARTING
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_timeout: current state 6:REQSENT
>
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 6:REQSENT
>
>
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 4 (TO+), action: 1006, new_state: 6 (REQSENT)
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_send_configure_request: current state 6:REQSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_process_configure_request: current state 6:REQSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 6:REQSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 6 (RCR+), action: 2008, new_state: 8 (ACKSENT)
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_send_configure_ack: current state 6:REQSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_process_configure_reject: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 9 (RCN), action: 1028, new_state: 8 (ACKSENT)
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_initialize_restart_count: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_send_configure_request: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_process_configure_nak: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 9 (RCN), action: 1028, new_state: 8 (ACKSENT)
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_initialize_restart_count: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_send_configure_request: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_process_configure_ack: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_generate_event: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 8 (RCA), action: 129, new_state: 9 (OPENED)
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp: pppcp_initialize_restart_count: current state 8:ACKSENT
> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: lcp: pppcp_generate_event: current state 9:OPENED

So we were able to negotiate IPCP parameters but network setup failed.

Are you running as root and is your tun module loaded?

Regards,
-Denis

^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: Unable to establish a complete PPP link on Sagem Hilo GPRS modem
  2012-08-20 13:29 ` Denis Kenzior
@ 2012-08-20 16:30   ` Schroeter Nicolas
  0 siblings, 0 replies; 3+ messages in thread
From: Schroeter Nicolas @ 2012-08-20 16:30 UTC (permalink / raw)
  To: ofono

[-- Attachment #1: Type: text/plain, Size: 6766 bytes --]


>Hi Nicolas,
>
><snip>
>
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: Aux:>
>>ATD*99***1#\r
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: Aux:<
>>\r\nCONNECT\r\n
>> Jan  2 16:25:14 109656587698 daemon.debug ofonod[600]:
>>drivers/atmodem/gprs-context.c:at_cgdata_cb() ok 1
>> Jan  2 16:25:14 109656587698 daemon.debug ofonod[600]:
>>drivers/atmodem/gprs-context.c:setup_ppp()
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_generate_event: current state 0:INITIAL
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 0
>>(Up), action: 2, new_state: 2 (CLOSED)
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_generate_event: current state 2:CLOSED
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 2
>>(Open), action: 1026, new_state: 6 (REQSENT)
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_initialize_restart_count: current state 2:CLOSED
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_send_configure_request: current state 2:CLOSED
>>
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP:
>>gatchat/gatppp.c:ppp_enter_phase() 1
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_process_configure_ack: current state 6:REQSENT
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_generate_event: current state 6:REQSENT
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 8
>>(RCA), action: 27, new_state: 7 (ACKRCVD)
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_initialize_restart_count: current state 6:REQSENT
>>
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_process_configure_request: current state 7:ACKRCVD
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_generate_event: current state 7:ACKRCVD
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 7
>>(RCR-), action: 4007, new_state: 7 (ACKRCVD)
>>
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_send_configure_nak: current state 7:ACKRCVD
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_process_configure_request: current state 7:ACKRCVD
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_generate_event: current state 7:ACKRCVD
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 6
>>(RCR+), action: 2109, new_state: 9 (OPENED)
>>
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_send_configure_ack: current state 7:ACKRCVD
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP:
>>gatchat/gatppp.c:ppp_enter_phase() 2
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP:
>>gatchat/gatppp.c:ppp_enter_phase() 3
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_generate_event: current state 0:INITIAL
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 2
>>(Open), action: 401, new_state: 1 (STARTING)
>>
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_generate_event: current state 1:STARTING
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: event: 0
>>(Up), action: 1026, new_state: 6 (REQSENT)
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_initialize_restart_count: current state 1:STARTING
>> Jan  2 16:25:14 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_send_configure_request: current state 1:STARTING
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_timeout: current state 6:REQSENT
>>
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_generate_event: current state 6:REQSENT
>>
>>
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 4
>>(TO+), action: 1006, new_state: 6 (REQSENT)
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_send_configure_request: current state 6:REQSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_process_configure_request: current state 6:REQSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_generate_event: current state 6:REQSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 6
>>(RCR+), action: 2008, new_state: 8 (ACKSENT)
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_send_configure_ack: current state 6:REQSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_process_configure_reject: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_generate_event: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 9
>>(RCN), action: 1028, new_state: 8 (ACKSENT)
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_initialize_restart_count: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_send_configure_request: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_process_configure_nak: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_generate_event: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 9
>>(RCN), action: 1028, new_state: 8 (ACKSENT)
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_initialize_restart_count: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_send_configure_request: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_process_configure_ack: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_generate_event: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: event: 8
>>(RCA), action: 129, new_state: 9 (OPENED)
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: ipcp:
>>pppcp_initialize_restart_count: current state 8:ACKSENT
>> Jan  2 16:25:18 109656587698 daemon.info ofonod[600]: PPP: lcp:
>>pppcp_generate_event: current state 9:OPENED
>
>So we were able to negotiate IPCP parameters but network setup failed.
>
>Are you running as root and is your tun module loaded?
>
>Regards,
>-Denis

Hi Denis,
Thank you for the advice. I forgot to configure the TUN device.
Now, the PPP link is established entirely.


Regards,
Nicolas


^ permalink raw reply	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2012-08-20 16:30 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2012-08-20  7:55 Unable to establish a complete PPP link on Sagem Hilo GPRS modem Schroeter Nicolas
2012-08-20 13:29 ` Denis Kenzior
2012-08-20 16:30   ` Schroeter Nicolas

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.