'ip-config-unavailable' error when USB modem tries to connect

Loading the ofono package did good, probably, but apparently your modem model, ZTE MF193E, is not on the ZTE list. Comparing it to other ZTE modems, eg MF190J, this modem is likely to need the same special udev rule, to run usb_modeswitch when the dongle is inserted, and to achieve that you may, as root, add a new udev rule to the file
/lib/udev/rules.d/40-usb_modeswitch.rules
with the following two lines e.g., somewhere near the # ZTE MF190J comment:

# ZTE MF193E
ATTR{idVendor}=="19d2", ATTR{idProduct}=="2003", RUN+="usb_modeswitch '%b/%k'"

plus a blank line, so it looks pleasant to the eye.

It's probably wise to reboot after that, only to find it all works like magic :-)

Or not. As you know, this is deep water for me, but if it still doesn't work, another ModemManager debug log would be needed, for another wild guess.

EDIT:

I'm now looking at the two lines in modemmanager.txt:

[mm-broadband-bearer.c:1254] connect(): Launching 3GPP connection attempt with APN 'WAP'

and

[mm-broadband-bearer.c:994] parse_pdp_list(): Found PDP context with CID 1 and PDP type ipv4 for APN 'wap'

I'm guessing the first refers to your broadband set up, while the latter refers to the internal binding to a "PDP context" (whatever that is). By the looks of it, the modem offers 9 alternative contexts, including one with apn='WAP', but the ModemManager settles for a case insensitive match.

The case difference might be the cause of the subsequent problem: e.g., that ppp wants a 'wap' configuration (rather than 'WAP') and doesn't find it, or that the remote end expects apn='WAP', but gets 'wap' which it chokes on.

The first option could easily be tested (and ruled out, probably) by changing your configuration to use 'wap' instead of 'WAP'. You may have tried this before, but at that time without the ofono package, so another test won't hurt, although the second option is more likely.

The second option is also more of a problem, given that there is an upper-case "PDP context" match available from the modem. Googling this issue, it appears that case insensitive match is correct by the (apparently relevant) specification "3GPP TS 23.003 chapter 9.1", and a patch to do this was added to ModemManager in November last year (into its version mm-1-4, I can gather). So in this case, your modem hasn't been told, and it expects case sensitive matching, while ModemManager unfortunately uses case insensitive matching straight out rather than as a fallback.

One solution for the second problem is of course to use a different ModemManager: either by finding and installing a version prior to this patch, or (with enough spare time), roll your own ModemManager. But neither is something to do at a whim, so maybe we need to browse around a bit to gain more evidence that this is (now) the problem, and if possible find other ways to work around it. Or with a bit of luck, someone who knows something drops by...

EDIT 2

Yes, version rollback is not easy due to dependencies. And rolling your own is far from a joy as well.

Two possible useful tools: command mmcli and (http://m2msupport.net/m2msupport/module-tester/).

The problem, I think, is that ModemManager picks PDP context 1 with apn='wap' where it should pick PDP context 9 with apn='WAP'. Maybe this can be addressed by using one of those tools. Either to be able to force a selection of 9 during connection, or by deleting the bad 'wap' contexts from the modem, which the module-tester tool is advertised to be capable of.

The modem-tester tool seems to be a java tool in the browser, so you need your browser set up to know where your java is, and you need that java to be known about. Then please explore that approach; I haven't used it myself, but seeing the screenshots, I'm guessing it will present the PDP contexts as the 'Data Calls' tab, where you first take note of everything it shows, and then edit the 'wap' entries to distort the 'wap' apn labels to be, say, 'wap1' and 'wap2' (so as to "hide" them when looking for 'WAP'). Then save and close, and juggle the dongle again. Grab a log; it seems syslog is sufficient now, in case it still refuses to play.

The mmcli command also seems useful in this story; do man mmcli to read about it, but I didn't see anything about PDP contexts there.

EDIT 3

Good call! to test from the DVD. That told us that I'm on the wrong track with the APN, and that it all lies in getting ppp to come up. At least, that'd be my new tree to bark at.

Firstly we take note that there's a version difference for pppd (from 2.4.5 to 2.4.6), but that's probably not an issue, as then everyone on a dongle would have been on this excursion.

Hmm, ppp; I need to stir up my last-millennium memories :-). Unfortunately I'm busy today, but I'll touch base when next I have time, to see how far you've come. My first back alleys to look into would be: 1) is the user in the right group? 2) are the credentials right? 3) are the ppp/chat configurations file mod's right? The ppp debug log comes out in nm.txt (as per a few days ago), but there should also be a way to ask it for more detailed logging.

EDIT 4

Ensure /etc/ppp/pap-secrets and /etc/ppp/chap-secrets have group dip (using chgrp as needed) and mode 740 (or -rw-r-----) (using chmod as needed). Mine didn't.

EDIT 5

How about this tree, then: Comparing the working wvdial syslog with non-working syslog, it seems that for some reason wvdial used ttyUSB3 while the non-working ModemManager keeps using ttyUSB1. I'm not sure if it's at all significant, but apparently but ttyUSB1 and ttyUSB3 both respond as AT capable modems.

So, as a test, maybe you can edit /etc/wvdial.conf so it under [Dialer Defaults] includes the line:

Modem = /dev/ttyUSB1

for the one test, and ttyUSB3 for another; both running as root; just to see if there is a different behaviour. Especially, if using ttyUSB1 is a problem whereas using ttyUSB3 is not, then it'd be good to look into how to make ModemManager use ttyUSB3 as well. For any other test outcome, I'd say we'll go back to chasing ferrets in ppp land.

EDIT 6

The dmesg log can be ignored I think; it's been like that in all logs. The new syslog only shows the ttyUSB3 test, but maybe we can assume that life gets better if NetworkManager can be tought to use ttyUSB3 and ignore ttyUSB1 (for this modem).

I also found (https://bugs.launchpad.net/ubuntu/+source/modemmanager/+bug/819784) with especially post #10 disconcerting :-(

The apparently applicable udev rule in /lib/udev/rules.d/77-mm-zte-port-types.rules doesn't apply, but'd supposedly be where to go. And, with only a very rudimentary, pre-101 insight into the udev magic, I would anyhow consider questioning its 4th line, which says:

SUBSYSTEM!="tty", GOTO="mm_zte_port_types_end"

I think that line needs an initial # so as to be commented out. In detail, my reading of the file is that it requires a calling state of SUBSYSTEM=="tty" and SUBSYSTEMS="usb" in order to use the good bits, including the "2003" product rules, and at least for testing, it should be safe to skip the "tty" filtering. And I don't have anything better right now.

EDIT 7

After having spent some quality time with my favourite search engine, I believe slightly more that the ttyUSB choice is a root problem here. The udev rule I pointed at is ok, and you should revert that edit.

However, I've started to believe that the configuration rules towards the end of that file, for product id "2003" are misleading. From the logs, it looks to me, that product id "2003" is actually the memory device side of the dongle, whereas the modem side has product id "1232". You can test this by replicating the two "2003" rules for product id "1232", in file /lib/udev/rules.d/77-mm-zte-port-types.rules

ATTRS{idVendor}=="19d2", ATTRS{idProduct}=="1232", ENV{.MM_USBIFNUM}=="03", ENV{ID_MM_ZTE_PORT_TYPE_MODEM}="1"
ATTRS{idVendor}=="19d2", ATTRS{idProduct}=="1232", ENV{.MM_USBIFNUM}=="01", ENV{ID_MM_ZTE_PORT_TYPE_AUX}="1"

or better, add a new file beside it, e.g. named 78-ralph.rules, but then you also need to add the SUBSYSTEM and SUBSYSTEMS protection around it.

Then, pull out the dongle, run udevadm control --reload (or reboot), and insert the dongle. And then yet another syslog capture, unless it now happens to work.

The effective problem, though, is that ModemManager discards the plugin libmm-plugin-zte.so at pre-probing, and ends up using a generic modem handler. If I'm right about product id, then this might be the reason; that pre-probing looks for a ID_MM_ZTE_PORT_TYPE_MODEM attribution, and this is lacking for product id "1232" (before the patch), with the effect that the zte plugin gets discarded.

EDIT 8

The syslog log is a bit short; missing the beginning where ModemManager fails to install the zte plugin. However, it's clear that the Generic modem plugin is used anyhow. Now, it may be that the usb_modeswitch rule I gave you early on is wrong as well; it decides to switch to "2003" when I thought it switched from "2003". But, man usb_modeswitch (which I should have looked at before) kind of suggest that it shifts to a product id rather than from it. In any case, the log shows that to happen. Thus, please change that rule to use "1232" instead, and try yet again.

If nothing else, at least I've got to learn a little bit about udev.

EDIT 9

Good. The problem is still (or also) that ModemManager drops the ZTE plugin at pre probing. The ModemManager debugging logs for 15.10 (log sets "debuglogs*") all tell the story that the ZTE plugin is discarded due to the vendor-id/product-id test.

Go to the source, Luke! I took this opportunity to sight the ModemManager source code briefly, and it indicates that the plugin as a table of vid/pid that doesn't include 19d2/2003 ... though, I haven't found that table source, so I couldn't verify.

Or maybe there's a timing issue here. E.g., that the ModemManager runs pre-probing while the device is 19d2/1232. That thought is aligned with the observation that having the 78-mm-zte-port-types-RALPH.rules udev rules makes ModemManager a little bit happier with the device. But then, why doesn't it stay happy and make use of that plugin when the device is switched to 19d2/2003?

Maybe more logs are needed :-) With ModemManager debugged, and also a capture of the command udevadm monitor --e |& tee udevadm.log (in another terminal) when you plug in the device. I got that command from (https://wiki.ubuntu.com/DebuggingUdev)

Do this two times: once without 78-mm-zte-port-types-RALPH.rules and once with the rules... both times from a fresh reboot. I.e.

1. setup /lib/udev/rules.d with or without the *-RALPH.rules file
2. pull out the device
3. reboot
4. setup ModemManager for debugging and setup udevadm capture
5. plug in the device and wait a minute
6. pack up log files
7. repeat from 1 with next test

That logging should tell where the ZTE plugin is dropped, and as I understand, it'll also tell about the udev event handling.

EDIT 10

(I'm almost at the end of my tether here, but I have one or two more breaths left:-)

Firstly, all the udev decorations seem to end up as they should, with just a couple of question marks in a couple of the attributes. In particular, the 78-*-RALPH.rules should be thrown away; it's not useful.

I think I can read out something from this, but I'm not exactly sure how it should be fixed. Basically, as I see it, when the dongle is plugged in there is a flurry of udev events. Focusing on those concerning ttyUSB1, there is an "early" event:

KERNEL[3867.310990] add      /devices/pci0000:00/0000:00:1d.7/usb1/1-8/1-8:1.1 (usb)

which causes the usb_serial driver to be loaded, and /dev/ttyUSB1 to appear. That in particular causes another event:

KERNEL[3867.435102] add      /devices/pci0000:00/0000:00:1d.7/usb1/1-8/1-8:1.1/ttyUSB1/tty/ttyUSB1 (tty)

I think that also triggers ModemManager. You have to go to syslog to see evidence of this, since there's no strict correlation between the logs. The event is time stamped 3867.435102, and syslog presents its nearest subsequent ModemManager log line just after a kernel log line stamped 3867.437412.

In my line of thinking, ModemManager should not be triggered yet, but only after the subsequent ttyUSB1 event:

UDEV  [3867.580427] add      /devices/pci0000:00/0000:00:1d.7/usb1/1-8/1-8:1.1/ttyUSB1/tty/ttyUSB1 (tty)

which has attached the ZTE attributes.

In the MM log, we would be at the line stamped 1449934745.363291, which apparently is a "real time" time stamp rather than a "kernel time" stamp.

ModemManager then is done with its pre-probing at1449934745.450398, i.e., 87ms later, which in kernel time terms would be near 3867.524519 and 55ms before that "good" UDEV event report above.

Note that in syslog, ModemManager does lodge complaints that ttyUSB1 does not have its attributes set, and maybe that complaint is related to the "marking" happening in 80-mm-candidate.rules. By the comment in that file, that marking appears to be an attempt to deal with exactly with this problem, but if so, it doesn't seem to work in this case.

Maybe one possibility to resolving this would be to change the "tty" rule in 80-mm-candidate.rules to be:

ENV{.ID_PORT}=="?*", SUBSYSTEM=="tty", ENV{ID_MM_CANDIDATE}="1"

In my mind, that would ensure that the ID_MM_CANDIDATE setting gets delayed until the ZTE attributes are set. The .ID_PORT setting is an effect of a 60-serial.rules rule (called 60-persistent-serial.rules before), and the added condition to the marking rule is simply that it has a value.

The condition is not exactly a ZTE attribute, only so as to keep the rule more generic. One step more specific would be to rather require ENV{.MM_USBIFNUM}="?*" instead, since that assignment here happens by 77-mm-zte-port-types.rules.

In general I'm not very sure about udev rule ordering, and I'm also not at all sure that this really stops ModemManager from acting too quickly. However if it doesn't, then 80-mm-candidate.rules would have little to no function, and maybe then it all would come down to the "improvements" to ModemManager from 15.04.

EDIT 21

sigh. Probably irrelevant, but you may want to check your 7-zte-mutil_port_device.rules file; is that a remnant from other experimentation? Anyhow, not relevant here.

There's still almost a second between 515.558184 and 516.381549 where ModemManager eagerly and erroneously grabs /dev/ttyUSB1, and whilst complaining about it not being set up, still goes through pre-probing and discards the ZTE plugin. In other words, the rule patch doesn't make ModemManager wait.

I suppose you also tested using ENV{.MM_USBIFNUM}="?*" instead of ENV{.ID_PORT}=="?*".

Actually, to confirm whether or not setting ENV{ID_MM_CANDIDATE}=1 is of any importance, you should temporarily move away 80-mm-candidate.rules, then see (in syslog) if then ModemManager ignores /dev/ttyUSB1 or not. I suspect "not".

And then, well, maybe you can use a working version, such as 14.04, and if you need, perhaps run 15.10 in a virtualbox, unless of course it's already all is in a virtualbox.

I think I need to claim defeat at this point.