trying to connect to different operators using --3gpp-register-in-operator

Sun Oct 15 08:37:15 UTC 2017

Hey,

> I have a problem when frequently changing operators
>
> I tried to connect to 3 different operators, first enable the modem, then
> try to register in operator, if successfully I use simple-connect and
> measure upload speed etc, then disconnect and disable modem and start over
> again
>
> Well I have some problems now to set up a stable way to connect to the 3rd
> operator
>
> When I enable the modem and try to use --3gpp-register-in-operator, it is
> hard to say if it succeeds, so if it doesn't, I just disconnect, disable and
> enable again, but when I disable the modem at that point it seems kind of
> busy doing something, but I don't understand what it actually does
>
> I tried to debug mm, but I still don't get it, I hope you don't mind me
> posting a piece of the debugging output here:
>
> ModemManager[4471]: <debug> [1507757863.162630]
> [huawei/mm-broadband-modem-huawei.c:2438] modem_load_signal_quality():
> loading signal quality...
> ModemManager[4471]: <debug> [1507757863.163091] [mm-broadband-modem.c:1991]
> modem_load_signal_quality(): loading signal quality...
> ModemManager[4471]: <debug> [1507757863.163565] [mm-port-serial.c:1237]
> mm_port_serial_open(): (ttyUSB0) device open count is 6 (open)
> ModemManager[4471]: <info>  [1507757864.691217] [mm-iface-modem.c:1392]
> __iface_modem_update_state_internal(): Modem
> /org/freedesktop/ModemManager1/Modem/0: state changed (registered ->
> disabling)
> ModemManager[4471]: <debug> [1507757864.705892] [mm-iface-modem.c:1165]
> update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0:
> signal quality updated (0)
> ModemManager[4471]: <debug> [1507757864.712021] [mm-iface-modem.c:1282]
> periodic_signal_quality_check_disable(): Periodic signal quality checks
> disabled
> ModemManager[4471]: <debug> [1507757864.713914] [mm-iface-modem.c:894]
> mm_iface_modem_update_access_technologies(): Modem
> /org/freedesktop/ModemManager1/Modem/0: access technology changed (umts ->
> unknown)
> ModemManager[4471]: <debug> [1507757864.719503] [mm-iface-modem.c:1008]
> periodic_access_technologies_check_disable(): Periodic access technology
> checks disabled
> ModemManager[4471]: <debug> [1507757864.726004] [mm-broadband-modem.c:8282]
> disabling_step(): Modem has messaging capabilities, disabling the Messaging
> interface...
> ModemManager[4471]: <debug> [1507757864.731147] [mm-broadband-modem.c:5791]
> set_messaging_unsolicited_events_handlers(): (ttyUSB0) Removing messaging
> unsolicited events handlers
> ModemManager[4471]: <debug> [1507757864.732277] [mm-broadband-modem.c:5791]
> set_messaging_unsolicited_events_handlers(): (ttyUSB2) Removing messaging
> unsolicited events handlers
> ModemManager[4471]: <debug> [1507757864.733760] [mm-broadband-modem.c:8294]
> disabling_step(): Modem has location capabilities, disabling the Location
> interface...
> ModemManager[4471]: <debug> [1507757864.734843]
> [mm-iface-modem-location.c:765] setup_gathering(): Need to disable the
> following location sources: '3gpp-lac-ci'
> ModemManager[4471]: <debug> [1507757864.744200] [mm-broadband-modem.c:8322]
> disabling_step(): Modem has 3GPP/USSD capabilities, disabling the Modem
> 3GPP/USSD interface...
> ModemManager[4471]: <debug> [1507757864.745383] [mm-port-serial.c:1237]
> mm_port_serial_open(): (ttyUSB0) device open count is 7 (open)
> ModemManager[4471]: <debug> [1507757917.238256] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB2): <-- '<CR><LF>^RSSI: 3<CR><LF>'
> ModemManager[4471]: <debug> [1507757917.248108] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): <-- '<CR><LF>^RSSI: 3<CR><LF><CR><LF>^HCSQ:
> "WCDMA",29,15,37<CR><LF>'
> ModemManager[4471]: <debug> [1507757917.249324]
> [huawei/mm-broadband-modem-huawei.c:1543] huawei_signal_changed(): 3GPP
> signal quality: 9
> ModemManager[4471]: <debug> [1507757917.256592] [mm-iface-modem.c:1165]
> update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0:
> signal quality updated (9)
> ModemManager[4471]: <debug> [1507757917.259668] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB2): <-- '<CR><LF>^HCSQ: "WCDMA",29,15,37<CR><LF>'
> ModemManager[4471]: <info>  [1507757938.156182] [mm-iface-modem-3gpp.c:1169]
> update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0:
> 3GPP Registration state changed (searching -> idle)
> ModemManager[4471]: <debug> [1507757938.162515] [mm-base-bearer.c:260]
> modem_3gpp_registration_state_changed(): Bearer not allowed to connect, not
> registered in 3GPP network
> ModemManager[4471]: <debug> [1507757938.163074] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB0) device open count is 6 (close)
> ModemManager[4471]: <debug> [1507757938.186571] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): --> 'AT+COPS=3,2;+COPS?<CR>'
> ModemManager[4471]: <debug> [1507757938.217214] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): <-- '<CR><LF>+COPS:
> 1,2,"26203",2<CR><LF><CR><LF>OK<CR><LF>'
> ModemManager[4471]: <debug> [1507757938.228361]
> [huawei/mm-broadband-modem-huawei.c:2038] modem_3gpp_load_operator_name():
> loading Operator Name (huawei)...
> ModemManager[4471]: <debug> [1507757938.230356] [mm-port-serial.c:1237]
> mm_port_serial_open(): (ttyUSB0) device open count is 7 (open)
> ModemManager[4471]: <debug> [1507757938.237333] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB0) device open count is 6 (close)
> ModemManager[4471]: <debug> [1507757938.239402] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): --> 'AT^SYSINFOEX<CR>'
> ModemManager[4471]: <debug> [1507757938.267262] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): <-- '<CR><LF>^SYSINFOEX:
> 2,3,1,1,,3,"WCDMA",41,"WCDMA"<CR><LF><CR><LF>OK<CR><LF>'
> ModemManager[4471]: <debug> [1507757938.268511]
> [huawei/mm-broadband-modem-huawei.c:582] load_access_technologies_finish():
> Access Technology: 'umts'
> ModemManager[4471]: <debug> [1507757938.269158] [mm-iface-modem.c:894]
> mm_iface_modem_update_access_technologies(): Modem
> /org/freedesktop/ModemManager1/Modem/0: access technology changed (unknown
> -> umts)
> ModemManager[4471]: <debug> [1507757938.269472] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB0) device open count is 5 (close)
> ModemManager[4471]: <debug> [1507757938.281278] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): --> 'AT+CSQ<CR>'
> ModemManager[4471]: <debug> [1507757938.296941] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): <-- '<CR><LF>+CSQ: 3,99<CR><LF><CR><LF>OK<CR><LF>'
> ModemManager[4471]: <debug> [1507757938.297864] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB0) device open count is 4 (close)
> ModemManager[4471]: <debug> [1507757938.298720] [mm-iface-modem.c:1165]
> update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0:
> signal quality updated (9)
> ModemManager[4471]: <debug> [1507757938.299179] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): --> 'AT+CSQ<CR>'
> ModemManager[4471]: <debug> [1507757938.312601] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): <-- '<CR><LF>+CSQ: 3,99<CR><LF><CR><LF>OK<CR><LF>'
> ModemManager[4471]: <debug> [1507757938.313516] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB0) device open count is 3 (close)
> ModemManager[4471]: <debug> [1507757938.314367] [mm-iface-modem.c:1165]
> update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0:
> signal quality updated (9)
> ModemManager[4471]: <debug> [1507757938.315042] [mm-broadband-modem.c:4908]
> set_unsolicited_result_code_handlers(): (ttyUSB0) Removing unsolicited
> result code handlers
> ModemManager[4471]: <debug> [1507757938.315297] [mm-broadband-modem.c:4908]
> set_unsolicited_result_code_handlers(): (ttyUSB2) Removing unsolicited
> result code handlers
> ModemManager[4471]: <debug> [1507757938.315563] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB0) device open count is 2 (close)
> ModemManager[4471]: <debug> [1507757938.327921] [mm-broadband-modem.c:8334]
> disabling_step(): Modem has 3GPP capabilities, disabling the Modem 3GPP
> interface...
> ModemManager[4471]: <debug> [1507757938.329574] [mm-iface-modem-3gpp.c:1310]
> periodic_registration_check_disable(): Periodic 3GPP registration checks
> disabled
> ModemManager[4471]: <debug> [1507757938.332616] [mm-port-serial.c:1237]
> mm_port_serial_open(): (ttyUSB0) device open count is 3 (open)
> ModemManager[4471]: <debug> [1507757938.335165] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): --> 'AT+COPS=3,0;+COPS?<CR>'
> ModemManager[4471]: <debug> [1507757938.370516] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): <-- '<CR><LF>+COPS:
> 1,0,"E-Plus",2<CR><LF><CR><LF>OK<CR><LF>'
> ModemManager[4471]: <debug> [1507757938.371558]
> [huawei/mm-broadband-modem-huawei.c:2028]
> modem_3gpp_load_operator_name_finish(): loaded Operator Name: E-Plus
> ModemManager[4471]: <debug> [1507757938.372172] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB0) device open count is 2 (close)
> ModemManager[4471]: <info>  [1507757938.379425] [mm-iface-modem-3gpp.c:1079]
> update_registration_reload_current_registration_info_ready(): Modem
> /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed
> (registering -> roaming)
> ModemManager[4471]: <debug> [1507757938.391976] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): --> 'AT+CREG=0<CR>'
> ModemManager[4471]: <debug> [1507757938.412542] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
> ModemManager[4471]: <debug> [1507757938.413389] [mm-port-serial.c:1237]
> mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
> ModemManager[4471]: <debug> [1507757938.413937] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB0) device open count is 1 (close)
> ModemManager[4471]: <debug> [1507757938.414343] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB2): --> 'AT+CREG=0<CR>'
> ModemManager[4471]: <debug> [1507757938.430404] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
> ModemManager[4471]: <debug> [1507757938.432294] [mm-port-serial.c:1237]
> mm_port_serial_open(): (ttyUSB0) device open count is 2 (open)
> ModemManager[4471]: <debug> [1507757938.432761] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB2) device open count is 1 (close)
> ModemManager[4471]: <debug> [1507757938.435627] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): --> 'AT+CGREG=0<CR>'
> ModemManager[4471]: <debug> [1507757938.461267] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
> ModemManager[4471]: <debug> [1507757938.462188] [mm-port-serial.c:1237]
> mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
> ModemManager[4471]: <debug> [1507757938.462626] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB0) device open count is 1 (close)
> ModemManager[4471]: <debug> [1507757938.463019] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB2): --> 'AT+CGREG=0<CR>'
> ModemManager[4471]: <debug> [1507757938.483758] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB2): <-- '<CR><LF>OK<CR><LF>'
> ModemManager[4471]: <debug> [1507757938.484400] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB2) device open count is 1 (close)
> ModemManager[4471]: <debug> [1507757938.486265] [mm-broadband-modem.c:3648]
> modem_3gpp_cleanup_unsolicited_registration_events(): (ttyUSB0) cleaning up
> unsolicited registration messages handlers
> ModemManager[4471]: <debug> [1507757938.489370] [mm-broadband-modem.c:3648]
> modem_3gpp_cleanup_unsolicited_registration_events(): (ttyUSB2) cleaning up
> unsolicited registration messages handlers
> ModemManager[4471]: <debug> [1507757938.497321] [mm-port-serial.c:1237]
> mm_port_serial_open(): (ttyUSB0) device open count is 2 (open)
> ModemManager[4471]: <debug> [1507757938.503806] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): --> 'AT^CURC=0<CR>'
> ModemManager[4471]: <debug> [1507757938.524718] [mm-port-serial-at.c:440]
> debug_log(): (ttyUSB0): <-- '<CR><LF>OK<CR><LF>'
> ModemManager[4471]: <debug> [1507757938.525473] [mm-port-serial.c:1296]
> mm_port_serial_close(): (ttyUSB0) device open count is 1 (close)
> ModemManager[4471]: <info>  [1507757938.526055] [mm-iface-modem-3gpp.c:1169]
> update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0:
> 3GPP Registration state changed (roaming -> unknown)
> ModemManager[4471]: <debug> [1507757938.530230] [mm-base-bearer.c:260]
> modem_3gpp_registration_state_changed(): Bearer not allowed to connect, not
> registered in 3GPP network
> ModemManager[4471]: <debug> [1507757938.537998] [mm-iface-modem.c:894]
> mm_iface_modem_update_access_technologies(): Modem
> /org/freedesktop/ModemManager1/Modem/0: access technology changed (umts ->
> unknown)
>
>
> I think the problem is somewhere here to find, but I just don't see the
> point
>
> The lines before those I just postet were about the
> --3gpp-register-in-operator, but as it failed, I just disconnected and
> disabled again, but it nevertheless seemed to update some signal quality
> stuff
>
> Is the problem something about that "Removing unsolicited result code
> handlers" and "cleaning up unsolicited registration messages handlers"
> stuff?
>
>
> Well I  should now also say something about the hardware I use:
>
> I'm using a Huawei ME909s-120 with the mmcli version 1.4.0
>
>
> I hope you can help me, as I really have no more idea what to do anymore
>
> If I can provide you any helpful information, just tell me
>
>

What's the error you get when trying to register in the operator manually?

The sequence you posted looks mostly good to me, all that happens when
you disable the modem (e.g. removing unsolicited message handlers,
disabling periodic polling of reg info or signal quality...). There is
one thing, though, that gets in the middle of the disabling sequence,
which is the "AT+COPS=3,0;+COPS?" call and its response, but that may
just be because it was scheduled before the disabling sequence started
to happen, but that shouldn't have any big effect, I think.

-- 
Aleksander
https://aleksander.es