bug reactivating primary context?

bug reactivating primary context?

[Mike Williams]

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

All,

Using connman/ofono to connect to a cellular network, the first time
activating the GPRS context works. After deactivation, the next
activation fails with an unknown error. I believe this is related to
this issue:
https://lists.01.org/pipermail/ofono/2015-May/015745.html

Looking through the code, it looks like at_gprs_activate_primary() fails at:

       if (g_at_chat_send(gcd->chat, buf, none_prefix,
                               at_cgdcont_cb, gc, NULL) > 0)
               return;

g_at_chat_send() is returning NULL from at_chat_send_common() because
the chat command_queue is NULL.

See ofono debug trace below with OFONO_PPP_DEBUG and OFONO_AT_DEBUG enabled:

ofonod[1366]: PPP: gatchat/gatppp.c:ppp_enter_phase() 4
ofonod[1366]: drivers/atmodem/gprs-context.c:ppp_connect()
ofonod[1366]: IP: 21.186.242.106
ofonod[1366]: DNS: 10.177.0.34, 10.168.187.116
ofonod[1366]: src/gprs.c:pri_activate_callback() 0xcd5b0
ofonod[1366]: plugins/udev.c:udev_event() subsystem net add
ofonod[1366]: plugins/udev.c:udev_event() subsystem net finished
ofonod[1366]: PCUI: < \r\n^MODE: 5,7\r\n
ofonod[1366]: plugins/udevng.c:check_modem_list()
ofonod[1366]: PCUI: <
\r\n^DSFLOWRPT:00000002,000000BB,00000041,0000000000000177,0000000000000082,0010E000,001F4000\r\n
ofonod[1366]: drivers/atmodem/gprs-context.c:at_gprs_deactivate_primary() cid 1
ofonod[1366]: PPP: lcp: pppcp_generate_event: current state 9:OPENED
ofonod[1366]: PPP: event: 3 (Close), action: 8224, new_state: 4 (CLOSING)
ofonod[1366]: PPP: lcp: pppcp_initialize_restart_count: current state 9:OPENED
ofonod[1366]: PPP: lcp: pppcp_send_terminate_request: current state 9:OPENED
ofonod[1366]: PPP: ipcp: pppcp_generate_event: current state 9:OPENED
ofonod[1366]: PPP: event: 1 (Down), action: 201, new_state: 1 (STARTING)
ofonod[1366]: PPP: gatchat/gatppp.c:ppp_enter_phase() 5
ofonod[1366]: plugins/udevng.c:remove_device() /sys/devices/virtual/net/ppp0
ofonod[1366]: plugins/udev.c:udev_event() subsystem net remove
ofonod[1366]: plugins/udev.c:remove_modem() /devices/virtual/net/ppp0
ofonod[1366]: plugins/udev.c:udev_event() subsystem net finished
ofonod[1366]: PPP: lcp: pppcp_process_terminate_ack: current state 4:CLOSING
ofonod[1366]: PPP: lcp: pppcp_generate_event: current state 4:CLOSING
ofonod[1366]: PPP: event: 11 (RTA), action: 802, new_state: 2 (CLOSED)
ofonod[1366]: PPP: lcp: pppcp_this_layer_finished: current state 2:CLOSED
ofonod[1366]: PPP: gatchat/gatppp.c:ppp_enter_phase() 0
ofonod[1366]: PCUI: < \r\n^MODE: 5,4\r\n
ofonod[1366]: PPP: gatchat/gatppp.c:ppp_dead()
ofonod[1366]: drivers/atmodem/gprs-context.c:ppp_disconnect() Reason: 6
ofonod[1366]: drivers/atmodem/gprs-context.c:at_gprs_activate_primary() cid 1
ofonod[1366]: src/gprs.c:pri_activate_callback() 0xcd5b0
ofonod[1366]: src/gprs.c:pri_activate_callback() Activating context
failed with error: Unknown error type
ofonod[1366]: PCUI: < \r\n^RSSI: 3\r\n
ofonod[1366]: src/network.c:ofono_netreg_strength_notify() strength 9


I have a test script that can reproduce this issue 100%. If necessary,
I can send it along.

This is using ofono 1.16 and connman 1.29 on a custom embedded system
generated by buildroot. I have three small patches applied, one for
ofono I got from the mailing list to support the e173, another for
ofono to allow duplicate APNs, and a third for connman to allow
autoconnecting cellular modems by specifying 'cellular' in
DefaultAutoConnectTechnologies. Unfortunately, I need all three to
enable my setup so I cannot test a pure source release.

Thanks,
Mike

Re: bug reactivating primary context?

[Alex J Lennon]

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

Hi Mike,

On 26/05/2015 17:38, Mike Williams wrote:
> All,
>
> Using connman/ofono to connect to a cellular network, the first time
> activating the GPRS context works. After deactivation, the next
> activation fails with an unknown error. I believe this is related to
> this issue:
> https://lists.01.org/pipermail/ofono/2015-May/015745.html
>
> Looking through the code, it looks like at_gprs_activate_primary() fails at:
>
>        if (g_at_chat_send(gcd->chat, buf, none_prefix,
>                                at_cgdcont_cb, gc, NULL) > 0)
>                return;
>
> g_at_chat_send() is returning NULL from at_chat_send_common() because
> the chat command_queue is NULL.
>
> See ofono debug trace below with OFONO_PPP_DEBUG and OFONO_AT_DEBUG enabled:
>
> ofonod[1366]: PPP: gatchat/gatppp.c:ppp_enter_phase() 4
> ofonod[1366]: drivers/atmodem/gprs-context.c:ppp_connect()
> ofonod[1366]: IP: 21.186.242.106
> ofonod[1366]: DNS: 10.177.0.34, 10.168.187.116
> ofonod[1366]: src/gprs.c:pri_activate_callback() 0xcd5b0
> ofonod[1366]: plugins/udev.c:udev_event() subsystem net add
> ofonod[1366]: plugins/udev.c:udev_event() subsystem net finished
> ofonod[1366]: PCUI: < \r\n^MODE: 5,7\r\n
> ofonod[1366]: plugins/udevng.c:check_modem_list()
> ofonod[1366]: PCUI: <
> \r\n^DSFLOWRPT:00000002,000000BB,00000041,0000000000000177,0000000000000082,0010E000,001F4000\r\n
> ofonod[1366]: drivers/atmodem/gprs-context.c:at_gprs_deactivate_primary() cid 1
> ofonod[1366]: PPP: lcp: pppcp_generate_event: current state 9:OPENED
> ofonod[1366]: PPP: event: 3 (Close), action: 8224, new_state: 4 (CLOSING)
> ofonod[1366]: PPP: lcp: pppcp_initialize_restart_count: current state 9:OPENED
> ofonod[1366]: PPP: lcp: pppcp_send_terminate_request: current state 9:OPENED
> ofonod[1366]: PPP: ipcp: pppcp_generate_event: current state 9:OPENED
> ofonod[1366]: PPP: event: 1 (Down), action: 201, new_state: 1 (STARTING)
> ofonod[1366]: PPP: gatchat/gatppp.c:ppp_enter_phase() 5
> ofonod[1366]: plugins/udevng.c:remove_device() /sys/devices/virtual/net/ppp0
> ofonod[1366]: plugins/udev.c:udev_event() subsystem net remove
> ofonod[1366]: plugins/udev.c:remove_modem() /devices/virtual/net/ppp0
> ofonod[1366]: plugins/udev.c:udev_event() subsystem net finished
> ofonod[1366]: PPP: lcp: pppcp_process_terminate_ack: current state 4:CLOSING
> ofonod[1366]: PPP: lcp: pppcp_generate_event: current state 4:CLOSING
> ofonod[1366]: PPP: event: 11 (RTA), action: 802, new_state: 2 (CLOSED)
> ofonod[1366]: PPP: lcp: pppcp_this_layer_finished: current state 2:CLOSED
> ofonod[1366]: PPP: gatchat/gatppp.c:ppp_enter_phase() 0
> ofonod[1366]: PCUI: < \r\n^MODE: 5,4\r\n
> ofonod[1366]: PPP: gatchat/gatppp.c:ppp_dead()
> ofonod[1366]: drivers/atmodem/gprs-context.c:ppp_disconnect() Reason: 6
> ofonod[1366]: drivers/atmodem/gprs-context.c:at_gprs_activate_primary() cid 1
> ofonod[1366]: src/gprs.c:pri_activate_callback() 0xcd5b0
> ofonod[1366]: src/gprs.c:pri_activate_callback() Activating context
> failed with error: Unknown error type
> ofonod[1366]: PCUI: < \r\n^RSSI: 3\r\n
> ofonod[1366]: src/network.c:ofono_netreg_strength_notify() strength 9
>
>
> I have a test script that can reproduce this issue 100%. If necessary,
> I can send it along.
>
> This is using ofono 1.16 and connman 1.29 on a custom embedded system
> generated by buildroot. I have three small patches applied, one for
> ofono I got from the mailing list to support the e173, another for
> ofono to allow duplicate APNs, and a third for connman to allow
> autoconnecting cellular modems by specifying 'cellular' in
> DefaultAutoConnectTechnologies. Unfortunately, I need all three to
> enable my setup so I cannot test a pure source release.

I too am having to make use of a patch to allow duplicate APNs - such a
thing would be useful in the source, as otherwise I can't auto-provision
various SIMs using the vanilla serviceproviders.xml

Would you mind sharing the auto connection patch for cellular as we have
been wondering here why configuring autoconnection didn't seem to make
any difference?

Thanks / Best Regards, Alex

Re: bug reactivating primary context?

[Denis Kenzior]

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

Hi Mike,

On 05/26/2015 10:38 AM, Mike Williams wrote:
> All,
>
> Using connman/ofono to connect to a cellular network, the first time
> activating the GPRS context works. After deactivation, the next
> activation fails with an unknown error. I believe this is related to
> this issue:
> https://lists.01.org/pipermail/ofono/2015-May/015745.html
>
> Looking through the code, it looks like at_gprs_activate_primary() fails at:
>
>         if (g_at_chat_send(gcd->chat, buf, none_prefix,
>                                 at_cgdcont_cb, gc, NULL) > 0)
>                 return;
>
> g_at_chat_send() is returning NULL from at_chat_send_common() because
> the chat command_queue is NULL.

That generally happens because the underlying AT command port for the 
GAtChat has been closed (most likely due to a serial line hangup).

What modem are you using?  Some manufacturers' modems are known to have 
this issue: whenever the PPP connection is dropped, the AT command port 
is closed by the modem.  Issuing AT&C0 should disable this behavior, but 
some modems do not honor that command.

Regards,
-Denis

Re: bug reactivating primary context?

[Mike Williams]

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

Denis,

On Tue, May 26, 2015 at 12:21 PM, Denis Kenzior <denkenz@gmail.com> wrote:
> Hi Mike,
>
> On 05/26/2015 10:38 AM, Mike Williams wrote:
>>
>> All,
>>
>> Using connman/ofono to connect to a cellular network, the first time
>> activating the GPRS context works. After deactivation, the next
>> activation fails with an unknown error. I believe this is related to
>> this issue:
>> https://lists.01.org/pipermail/ofono/2015-May/015745.html
>>
>> Looking through the code, it looks like at_gprs_activate_primary() fails
>> at:
>>
>>         if (g_at_chat_send(gcd->chat, buf, none_prefix,
>>                                 at_cgdcont_cb, gc, NULL) > 0)
>>                 return;
>>
>> g_at_chat_send() is returning NULL from at_chat_send_common() because
>> the chat command_queue is NULL.
>
>
> That generally happens because the underlying AT command port for the
> GAtChat has been closed (most likely due to a serial line hangup).
>
> What modem are you using?  Some manufacturers' modems are known to have this
> issue: whenever the PPP connection is dropped, the AT command port is closed
> by the modem.  Issuing AT&C0 should disable this behavior, but some modems
> do not honor that command.

It looks like AT&C0 is correctly being issued, from the logs here:

ofonod[1398]: plugins/huawei.c:sysinfo_enable_cb() 255 -> 1
ofonod[1398]: Modem: > AT&C0\r
ofonod[1398]: PCUI: > AT&C0\r
ofonod[1398]: PCUI: < \r\nOK\r\n

I'm using a Huawei e173:
ofonod[2008]: Modem: < ATE0 +CMEE=1\r\r\nOK\r\n
ofonod[2008]: PCUI: < \r\nManufacturer: huawei\r\nModel:
E173L\r\nRevision: 21.106.04.00.982\r\nIMEI: 868387000063372\r\n+GCAP:
+CGSM,+DS,+ES\r\n\r\nOK\r\n

Is there any way I can see if the modem is closing the command port?

Mike

Re: bug reactivating primary context?

[Mike Williams]

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

Alex,

On Tue, May 26, 2015 at 12:20 PM, Alex J Lennon
<ajlennon@dynamicdevices.co.uk> wrote:
> Would you mind sharing the auto connection patch for cellular as we have
> been wondering here why configuring autoconnection didn't seem to make
> any difference?


It's actually a patch for connman, which needs cellular services set
with favorite=true as well as autoconnect=true before it will
automatically connect them. connman correctly parses 'cellular' out of
DefaultAutoConnectTechnologies and sets the autocorrect property for
cellular services, so this patch just sets those services' favorite
property to the autoconnect property when they are created.

I'm a complete beginner to the connman/ofono source code though, so
use this patch at your own risk :).

Mike


From 39a7e2849cb2f53bcc461d5cbf2ccc236e498dc9 Mon Sep 17 00:00:00 2001
From: Mike Williams <mike@mikebwilliams.com>
Date: Mon, 18 May 2015 14:44:00 -0400
Subject: [PATCH] cellular: allow autoconnecting if configured

---
src/service.c | 4 +++-
1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/src/service.c b/src/service.c
index 7243ea2..b14623c 100644
--- a/src/service.c
+++ b/src/service.c
@@ -6698,9 +6698,11 @@ struct connman_service *
__connman_service_create_from_network(struct connman_ne
       case CONNMAN_SERVICE_TYPE_VPN:
       case CONNMAN_SERVICE_TYPE_GADGET:
       case CONNMAN_SERVICE_TYPE_WIFI:
-       case CONNMAN_SERVICE_TYPE_CELLULAR:
       case CONNMAN_SERVICE_TYPE_P2P:
               break;
+       case CONNMAN_SERVICE_TYPE_CELLULAR:
+               service->favorite = service->autoconnect;
+               break;
       case CONNMAN_SERVICE_TYPE_ETHERNET:
               service->favorite = true;
               break;
--
2.1.4

Re: bug reactivating primary context?

[Alex J Lennon]

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



On 27/05/2015 18:58, Mike Williams wrote:
> Alex,
>
> On Tue, May 26, 2015 at 12:20 PM, Alex J Lennon
> <ajlennon@dynamicdevices.co.uk> wrote:
>> Would you mind sharing the auto connection patch for cellular as we have
>> been wondering here why configuring autoconnection didn't seem to make
>> any difference?
>
> It's actually a patch for connman, which needs cellular services set
> with favorite=true as well as autoconnect=true before it will
> automatically connect them. connman correctly parses 'cellular' out of
> DefaultAutoConnectTechnologies and sets the autocorrect property for
> cellular services, so this patch just sets those services' favorite
> property to the autoconnect property when they are created.
>
> I'm a complete beginner to the connman/ofono source code though, so
> use this patch at your own risk :).
>
> Mike

Thanks Mike - that sounds very much like what we need.

I had resorted to a script which forced a connection of all cellular_foo
services to cause connman to connect the service and thus set the
"favourite" property

re: beginner - me too (although I have spent more time than I care to
recall fighting with PPP and modem AT command-sets over the years! :)

Thanks again,

Alex

Re: bug reactivating primary context?

[Alex J Lennon]

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

Hi Denis,

On 26/05/2015 18:21, Denis Kenzior wrote:
> Hi Mike,
>
> On 05/26/2015 10:38 AM, Mike Williams wrote:
>> All,
>>
>> Using connman/ofono to connect to a cellular network, the first time
>> activating the GPRS context works. After deactivation, the next
>> activation fails with an unknown error. I believe this is related to
>> this issue:
>> https://lists.01.org/pipermail/ofono/2015-May/015745.html
>>
>> Looking through the code, it looks like at_gprs_activate_primary()
>> fails at:
>>
>>         if (g_at_chat_send(gcd->chat, buf, none_prefix,
>>                                 at_cgdcont_cb, gc, NULL) > 0)
>>                 return;
>>
>> g_at_chat_send() is returning NULL from at_chat_send_common() because
>> the chat command_queue is NULL.
>
> That generally happens because the underlying AT command port for the
> GAtChat has been closed (most likely due to a serial line hangup).
>
> What modem are you using?  Some manufacturers' modems are known to
> have this issue: whenever the PPP connection is dropped, the AT
> command port is closed by the modem.  Issuing AT&C0 should disable
> this behavior, but some modems do not honor that command. 

I'd like just to verify that this isn't an issue for Cinterion devices /
plugin.  Is it fair to assume that if there is an issue with context
activation and deactivation then I would not have a ppp0 interface
brought up after running the context deactivation and activation test
scripts?

[ all working - connected on ppp0 ]
/usr/lib/ofono/test/deactivate-context
/usr/lib/ofono/test/activate-context
[ all working - connected on ppp0 ]

That all seems OK here on Cinterion EHS6.

Thanks,

Alex

Re: bug reactivating primary context?

[Denis Kenzior]

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

Hi Mike,

>
> It looks like AT&C0 is correctly being issued, from the logs here:
>
> ofonod[1398]: plugins/huawei.c:sysinfo_enable_cb() 255 -> 1
> ofonod[1398]: Modem: > AT&C0\r
> ofonod[1398]: PCUI: > AT&C0\r
> ofonod[1398]: PCUI: < \r\nOK\r\n
>
> I'm using a Huawei e173:
> ofonod[2008]: Modem: < ATE0 +CMEE=1\r\r\nOK\r\n
> ofonod[2008]: PCUI: < \r\nManufacturer: huawei\r\nModel:
> E173L\r\nRevision: 21.106.04.00.982\r\nIMEI: 868387000063372\r\n+GCAP:
> +CGSM,+DS,+ES\r\n\r\nOK\r\n

Yes, certain models of Huawei modems are the main culprits.  There have 
been a few suggestions on how to solve this, but it is quite nasty & 
requires re-opening the AT modem port.  Nobody had the itch to fix it 
properly.

>
> Is there any way I can see if the modem is closing the command port?
>

strace, or use g_at_chat_set_disconnect_function() and see if that gets 
called.

Regards,
-Denis

Re: bug reactivating primary context?

[Denis Kenzior]

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

Hi Alex,

 >
> I'd like just to verify that this isn't an issue for Cinterion devices /
> plugin.  Is it fair to assume that if there is an issue with context
> activation and deactivation then I would not have a ppp0 interface
> brought up after running the context deactivation and activation test
> scripts?

Correct.  I do not recall that this particular issue was ever reported 
for Cinterion devices.  Only certain models of Huawei modems & maybe one 
or two other USB stick type devices.

>
> [ all working - connected on ppp0 ]
> /usr/lib/ofono/test/deactivate-context
> /usr/lib/ofono/test/activate-context
> [ all working - connected on ppp0 ]
>
> That all seems OK here on Cinterion EHS6.
>

Good to know.  Thanks for confirming this one.

Regards,
-Denis

Re: bug reactivating primary context?

[Mike Williams]

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

Denis,

On Wed, May 27, 2015 at 1:14 PM, Denis Kenzior <denkenz@gmail.com> wrote:
> Hi Mike,
>
>>
>> It looks like AT&C0 is correctly being issued, from the logs here:
>>
>> ofonod[1398]: plugins/huawei.c:sysinfo_enable_cb() 255 -> 1
>> ofonod[1398]: Modem: > AT&C0\r
>> ofonod[1398]: PCUI: > AT&C0\r
>> ofonod[1398]: PCUI: < \r\nOK\r\n
>>
>> I'm using a Huawei e173:
>> ofonod[2008]: Modem: < ATE0 +CMEE=1\r\r\nOK\r\n
>> ofonod[2008]: PCUI: < \r\nManufacturer: huawei\r\nModel:
>> E173L\r\nRevision: 21.106.04.00.982\r\nIMEI: 868387000063372\r\n+GCAP:
>> +CGSM,+DS,+ES\r\n\r\nOK\r\n
>
>
> Yes, certain models of Huawei modems are the main culprits.  There have been
> a few suggestions on how to solve this, but it is quite nasty & requires
> re-opening the AT modem port.  Nobody had the itch to fix it properly.
>
>>
>> Is there any way I can see if the modem is closing the command port?
>>
>
> strace, or use g_at_chat_set_disconnect_function() and see if that gets
> called.

It looks like polling the fd for ttyUSB3 returns POLLHUP. Opened here:

writev(2, [{"ofonod[2619]: plugins/huawei.c:o"..., 63}, {"\n", 1}],
2ofonod[2619]: plugins/huawei.c:open_device() Modem /dev/ttyUSB3
) = 64
send(5, "<31>May 27 12:42:50 ofonod[2619]"..., 83, MSG_NOSIGNAL) = 83
open("/dev/ttyUSB3", O_RDWR|O_NOCTTY|O_NONBLOCK|O_LARGEFILE) = 10


PPP disconnect and then poll() returning POLLHUP:

writev(2, [{"ofonod[2619]: drivers/atmodem/gp"..., 71}, {"\n", 1}],
2ofonod[2619]: drivers/atmodem/gprs-context.c:ppp_disconnect() Reason:
6
) = 72
send(5, "<31>May 27 12:43:56 ofonod[2619]"..., 91, MSG_NOSIGNAL) = 91
sendmsg(6, {msg_name(0)=NULL,
msg_iov(2)=[{"l\2\1\1\0\0\0\0<\0\0\0\30\0\0\0\6\1s\0\5\0\0\0:1.69\0\0\0"...,
40}, {"", 0}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 40
sendmsg(6, {msg_name(0)=NULL,
msg_iov(2)=[{"l\4\1\1\30\0\0\0=\0\0\0h\0\0\0\1\1o\0\22\0\0\0/huawei_"...,
120}, {"\10\0\0\0Settings\0\5a{sv}\0\0\0\0\0", 24}], msg_controllen=0,
msg_flags=0}, MSG_NOSIGNAL) = 144
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 12
ioctl(12, SIOCGIFFLAGS, {ifr_name="ppp0", ???}) = -1 ENODEV (No such device)
close(12)                               = 0
sendmsg(6, {msg_name(0)=NULL,
msg_iov(2)=[{"l\4\1\1\24\0\0\0>\0\0\0h\0\0\0\1\1o\0\22\0\0\0/huawei_"...,
120}, {"\6\0\0\0Active\0\1b\0\0\0\0\0\0\0", 20}], msg_controllen=0,
msg_flags=0}, MSG_NOSIGNAL) = 140
poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=11,
events=POLLIN}, {fd=6, events=POLLIN}, {fd=7, events=POLLIN}, {fd=10,
events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 8, -1)
= 1 ([{fd=10, revents=POLLIN|POLLERR|
POLLHUP}])
read(3, 0xbe9f5af0, 16)                 = -1 EAGAIN (Resource
temporarily unavailable)
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
read(10, "", 8192)                      = 0
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
close(10)


Any simple ways to fix this, and are all Huawei USB modems subject to
this? This was for prototyping on an embedded system, can anyone give
recommendations for good modems that are known to work well with
ofono?

Thanks,
Mike

Re: bug reactivating primary context?

[Denis Kenzior]

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

Mike,

 > PPP disconnect and then poll() returning POLLHUP:
>

Sounds like you confirmed my suspicion.

>
> Any simple ways to fix this, and are all Huawei USB modems subject to

No simple ways.  I have many Huawei modems and only a few exhibit this 
behavior.  Perhaps try to upgrade the firmware?

> this? This was for prototyping on an embedded system, can anyone give
> recommendations for good modems that are known to work well with
> ofono?

We've had good luck with Option USB sticks and a several from Sony Ericsson.

Regards,
-Denis