Quectel EC200T USB: Problems with context activation in chineese networks

Quectel EC200T USB: Problems with context activation in chineese networks

[Sergei Golubtsov]

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

Hi Denis and all,

I have some problems with the context activation on Quectel EC200T USB in
chinese network although in russian networks the modem works fine.

I have the following during the activation:

2021-05-18T23:35:50.624972+03:00 ofonod[999]: [info] Modem: <
\r\nCONNECT\r\n
2021-05-18T23:35:50.625854+03:00 ofonod[999]: [debug]
../git/ofono/drivers/atmodem/gprs-context.c:at_cgdata_cb() ok 1
2021-05-18T23:35:50.626564+03:00 ofonod[999]: [debug]
../git/ofono/drivers/atmodem/gprs-context.c:setup_ppp()
2021-05-18T23:35:50.627463+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_generate_event: current state 0:INITIAL
2021-05-18T23:35:50.628216+03:00 ofonod[999]: [info] PPP: event: 0 (Up),
action: 2, new_state: 2 (CLOSED)
2021-05-18T23:35:50.628884+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_generate_event: current state 2:CLOSED
2021-05-18T23:35:50.629521+03:00 ofonod[999]: [info] PPP: event: 2 (Open),
action: 1026, new_state: 6 (REQSENT)
2021-05-18T23:35:50.630234+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_initialize_restart_count: current state 2:CLOSED
2021-05-18T23:35:50.630876+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_send_configure_request: current state 2:CLOSED
2021-05-18T23:35:50.631641+03:00 ofonod[999]: [info] PPP:
../git/ofono/gatchat/gatppp.c:ppp_enter_phase() 1
2021-05-18T23:35:50.634253+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_process_configure_request: current state 6:REQSENT
2021-05-18T23:35:50.635270+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_generate_event: current state 6:REQSENT
2021-05-18T23:35:50.635423+03:00 ofonod[999]: [info] PPP: event: 7 (RCR-),
action: 4006, new_state: 6 (REQSENT)
2021-05-18T23:35:50.635544+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_send_configure_nak: current state 6:REQSENT
2021-05-18T23:35:50.636566+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_process_configure_ack: current state 6:REQSENT
2021-05-18T23:35:50.636696+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_generate_event: current state 6:REQSENT
2021-05-18T23:35:50.637067+03:00 ofonod[999]: [info] PPP: event: 8 (RCA),
action: 27, new_state: 7 (ACKRCVD)
2021-05-18T23:35:50.637187+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_initialize_restart_count: current state 6:REQSENT
2021-05-18T23:35:50.637187+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_initialize_restart_count: current state 6:REQSENT
2021-05-18T23:35:50.637597+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_process_configure_request: current state 7:ACKRCVD
2021-05-18T23:35:50.637715+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_generate_event: current state 7:ACKRCVD
2021-05-18T23:35:50.637826+03:00 ofonod[999]: [info] PPP: event: 7 (RCR-),
action: 4007, new_state: 7 (ACKRCVD)
2021-05-18T23:35:50.637929+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_send_configure_nak: current state 7:ACKRCVD
2021-05-18T23:35:50.639907+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_process_configure_request: current state 7:ACKRCVD
2021-05-18T23:35:50.640246+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_generate_event: current state 7:ACKRCVD
2021-05-18T23:35:50.640992+03:00 ofonod[999]: [info] PPP: event: 7 (RCR-),
action: 4007, new_state: 7 (ACKRCVD)

So, the following lines repeats infinitely, context is not activated and
ofono uses ~90% of the CPU until I stop it:

2021-05-18T23:35:50.637929+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_send_configure_nak: current state 7:ACKRCVD
2021-05-18T23:35:50.639907+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_process_configure_request: current state 7:ACKRCVD
2021-05-18T23:35:50.640246+03:00 ofonod[999]: [info] PPP: lcp:
pppcp_generate_event: current state 7:ACKRCVD
2021-05-18T23:35:50.640992+03:00 ofonod[999]: [info] PPP: event: 7 (RCR-),
action: 4007, new_state: 7 (ACKRCVD)

Could someone shed a light on what is going on there and how to solve that?

Thanks in advance.
Have a nice day.

Yours sincerely,
Sergei Golubtsov.

[-- Attachment #2: attachment.htm --]
[-- Type: text/html, Size: 5027 bytes --]

Re: Quectel EC200T USB: Problems with context activation

[Denis Kenzior]

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

Hi Sergei,

On 5/18/21 4:19 PM, Sergei Golubtsov wrote:
> Hi Denis and all,
> 
> I have some problems with the context activation on Quectel EC200T USB in 
> chinese network although in russian networks the modem works fine.
> 
> I have the following during the activation:
> 
> 2021-05-18T23:35:50.624972+03:00 ofonod[999]: [info] Modem: < \r\nCONNECT\r\n
> 2021-05-18T23:35:50.625854+03:00 ofonod[999]: [debug] 
> ../git/ofono/drivers/atmodem/gprs-context.c:at_cgdata_cb() ok 1
> 2021-05-18T23:35:50.626564+03:00 ofonod[999]: [debug] 
> ../git/ofono/drivers/atmodem/gprs-context.c:setup_ppp()
> 2021-05-18T23:35:50.627463+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_generate_event: current state 0:INITIAL
> 2021-05-18T23:35:50.628216+03:00 ofonod[999]: [info] PPP: event: 0 (Up), action: 
> 2, new_state: 2 (CLOSED)
> 2021-05-18T23:35:50.628884+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_generate_event: current state 2:CLOSED
> 2021-05-18T23:35:50.629521+03:00 ofonod[999]: [info] PPP: event: 2 (Open), 
> action: 1026, new_state: 6 (REQSENT)
> 2021-05-18T23:35:50.630234+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_initialize_restart_count: current state 2:CLOSED
> 2021-05-18T23:35:50.630876+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_send_configure_request: current state 2:CLOSED
> 2021-05-18T23:35:50.631641+03:00 ofonod[999]: [info] PPP: 
> ../git/ofono/gatchat/gatppp.c:ppp_enter_phase() 1
> 2021-05-18T23:35:50.634253+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_process_configure_request: current state 6:REQSENT
> 2021-05-18T23:35:50.635270+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_generate_event: current state 6:REQSENT
> 2021-05-18T23:35:50.635423+03:00 ofonod[999]: [info] PPP: event: 7 (RCR-), 
> action: 4006, new_state: 6 (REQSENT)

Peer is sending us options we do not find acceptable...  Do you have a wireshark 
trace to see what this might be?

> 2021-05-18T23:35:50.635544+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_send_configure_nak: current state 6:REQSENT
> 2021-05-18T23:35:50.636566+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_process_configure_ack: current state 6:REQSENT

Looks like our options (that we're sending) are accepted by the peer

> 2021-05-18T23:35:50.636696+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_generate_event: current state 6:REQSENT
> 2021-05-18T23:35:50.637067+03:00 ofonod[999]: [info] PPP: event: 8 (RCA), 
> action: 27, new_state: 7 (ACKRCVD)
> 2021-05-18T23:35:50.637187+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_initialize_restart_count: current state 6:REQSENT
> 2021-05-18T23:35:50.637187+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_initialize_restart_count: current state 6:REQSENT
> 2021-05-18T23:35:50.637597+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_process_configure_request: current state 7:ACKRCVD
> 2021-05-18T23:35:50.637715+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_generate_event: current state 7:ACKRCVD
> 2021-05-18T23:35:50.637826+03:00 ofonod[999]: [info] PPP: event: 7 (RCR-), 
> action: 4007, new_state: 7 (ACKRCVD)
> 2021-05-18T23:35:50.637929+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_send_configure_nak: current state 7:ACKRCVD
> 2021-05-18T23:35:50.639907+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_process_configure_request: current state 7:ACKRCVD
> 2021-05-18T23:35:50.640246+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_generate_event: current state 7:ACKRCVD
> 2021-05-18T23:35:50.640992+03:00 ofonod[999]: [info] PPP: event: 7 (RCR-), 
> action: 4007, new_state: 7 (ACKRCVD)

and basically we get into an infinite loop with the peer trying to set some 
options we find unacceptable..

> 
> So, the following lines repeats infinitely, context is not activated and ofono 
> uses ~90% of the CPU until I stop it:
> 2021-05-18T23:35:50.637929+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_send_configure_nak: current state 7:ACKRCVD
> 2021-05-18T23:35:50.639907+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_process_configure_request: current state 7:ACKRCVD
> 2021-05-18T23:35:50.640246+03:00 ofonod[999]: [info] PPP: lcp: 
> pppcp_generate_event: current state 7:ACKRCVD
> 2021-05-18T23:35:50.640992+03:00 ofonod[999]: [info] PPP: event: 7 (RCR-), 
> action: 4007, new_state: 7 (ACKRCVD)
> 
> Could someone shed a light on what is going on there and how to solve that?
> 
> Thanks in advance.
> Have a nice day.
> 
> Yours sincerely,
> Sergei Golubtsov.

Regards,
-Denis

Re: Quectel EC200T USB: Problems with context activation

[Sergei Golubtsov]

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

Hi Denis,

Thank you very much for your quick and helpful reply.

The problem is a bit vulgar actually. That's a shame that I took your
time for that but I have another question as I am not sure about the
findings below.

I had tried to get dump with gsmdial and gsmdial successfully
activated the context. So the problem is that we have authentication
method set to NONE in ofono. But gsmdial uses CHAP by default.
I have manually set the auth to CHAP for the context in ofono and
ofono successfully activated the context.
There is the provider info from mobile-broadband-provider-info about
my provider:

    <provider>
    <name>China Unicom</name>
    <gsm>
    <network-id mcc="460" mnc="01"/>
    <apn value="3gnet">
    <plan type="postpaid"/>
    <usage type="internet"/>
    <username>uninet</username>
    </apn>
    <apn value="3gwap">
    <usage type="mms"/>
    <name>联通彩信</name>
    <mmsc>http://mmsc.myuni.com.cn</mmsc>
    <mmsproxy>10.0.0.172:80</mmsproxy>
    </apn>
    </gsm>
    </provider>


Am I correct that ofono must use CHAP if the auth method is not
specified in the db?

I see that the technology used by the modem is HSPA. And I see the
following in ofono/drivers/atmodem/lte.c:

    /* change the authentication method if the  parameters are invalid */
    if (!*ldd->pending_info.username || !*ldd->pending_info.password)
       auth_method = OFONO_GPRS_AUTH_METHOD_NONE;


And in ofono/plugins/mbpi.c:

    /* select authentication method NONE if fit */
    if (!ap->username || !ap->password)
    ap->auth_method = OFONO_GPRS_AUTH_METHOD_NONE;


As well as ofono/plugins/fileprovision.c::

    /* select default authentication method */
    (*settings)[0].auth_method = OFONO_GPRS_AUTH_METHOD_NONE;


ofono/src/lte.c:

    /* this must have a valid default */
   if (!gprs_auth_method_from_string(auth_method_str,
   &lte->info.auth_method))
   lte->info.auth_method = OFONO_GPRS_AUTH_METHOD_NONE;


I am not sure about the standards which may be relevant here. Sorry
for asking this but I thought that we should use CHAP by default,
don't we?

Thank you again and have a nice day.

Yours sincerely,
Sergei Golubtsov.

Re: Quectel EC200T USB: Problems with context activation

[Denis Kenzior]

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

Hi Sergei,

On 5/19/21 6:35 PM, Sergei Golubtsov wrote:
> Hi Denis,
> 
> Thank you very much for your quick and helpful reply.
> 
> The problem is a bit vulgar actually. That's a shame that I took your
> time for that but I have another question as I am not sure about the
> findings below.

no worries.

> 
> I had tried to get dump with gsmdial and gsmdial successfully
> activated the context. So the problem is that we have authentication
> method set to NONE in ofono. But gsmdial uses CHAP by default.
> I have manually set the auth to CHAP for the context in ofono and
> ofono successfully activated the context.

Yes, oFono used to use CHAP by default, but this was changed a few years ago.

> There is the provider info from mobile-broadband-provider-info about
> my provider:
> 
>      <provider>
>      <name>China Unicom</name>
>      <gsm>
>      <network-id mcc="460" mnc="01"/>
>      <apn value="3gnet">
>      <plan type="postpaid"/>
>      <usage type="internet"/>
>      <username>uninet</username>
>      </apn>
>      <apn value="3gwap">
>      <usage type="mms"/>
>      <name>联通彩信</name>
>      <mmsc>http://mmsc.myuni.com.cn</mmsc>
>      <mmsproxy>10.0.0.172:80</mmsproxy>
>      </apn>
>      </gsm>
>      </provider>
> 
> 
> Am I correct that ofono must use CHAP if the auth method is not
> specified in the db?

We used to do this, then around Sep-Oct 2018 there was a strong push to add an 
explicit 'No Authentication' option for oFono from one of the modem hardware 
vendors.  I don't recall the exact arguments, search the archives, but the 
fallout was that an empty username / password implied no authentication.  Which 
I think does make a certain amount of sense.

git show 6cf24fe1f9cfa2a61422ad84abfdd32e7ea2cf78.  Look around at the commits 
from the same author.  I do seem to recall that 3GPP mandated CHAP to be used as 
the default, even in the no username / password case.  But my memory is fuzzy 
now, and there hasn't been any problems reported since then (until now).

> 
> I see that the technology used by the modem is HSPA. And I see the
> following in ofono/drivers/atmodem/lte.c:
> 
>      /* change the authentication method if the  parameters are invalid */
>      if (!*ldd->pending_info.username || !*ldd->pending_info.password)
>         auth_method = OFONO_GPRS_AUTH_METHOD_NONE;
> 
> 
> And in ofono/plugins/mbpi.c:
> 
>      /* select authentication method NONE if fit */
>      if (!ap->username || !ap->password)
>      ap->auth_method = OFONO_GPRS_AUTH_METHOD_NONE;
> 
> 
> As well as ofono/plugins/fileprovision.c::
> 
>      /* select default authentication method */
>      (*settings)[0].auth_method = OFONO_GPRS_AUTH_METHOD_NONE;
> 
> 
> ofono/src/lte.c:
> 
>      /* this must have a valid default */
>     if (!gprs_auth_method_from_string(auth_method_str,
>     &lte->info.auth_method))
>     lte->info.auth_method = OFONO_GPRS_AUTH_METHOD_NONE;
> 
> 
> I am not sure about the standards which may be relevant here. Sorry
> for asking this but I thought that we should use CHAP by default,
> don't we?

The question is really whether it is the network or the modem at fault here. 
Does AUTH_METHOD_NONE work on other networks with this hardware?

> 
> Thank you again and have a nice day.
> 
> Yours sincerely,
> Sergei Golubtsov.
> 

Regards,
-Denis