wda-get-data-format randomly returns error: couldn't create client for the 'wda' service

Tor Rune Skoglund trs at fourc.eu
Thu Apr 16 07:33:10 UTC 2020


Hi Dan,

Den 15.04.2020 18:54, skrev Dan Williams:
> On Wed, 2020-04-15 at 10:57 +0200, Tor Rune Skoglund wrote:
>> Hi Dan,
>>
>> thank you very much for your input.
>>
>> Den 14.04.2020 21:17, skrev Dan Williams:
>>
>>   >If you really need to switch to 802-3 mode, OK. But that needs ot
>>> happen on both ends: QMI (eg what the firmware expects) and the
>>> kernel
>>> .  This command only changes one (firmware).
>>>
>>> You also need to change the kernel side with --set-expected-data-
>>> format=<same>.  Both need to agree.
>>>
>>> qmicli will try to do this for you, but as you see below it fails.
>>>
>>> In any case, try both the --wda-set-data-format and --set-expected-
>>> data-format.
>>>
>>> If that works, then we can move on to the pdn-ipv6-call-disallowed
>>> issue. For that, please add the "-v" flag (for verbose mode) when
>>> calling --wds-start-network so we can see the actual QMI commands
>>> passed to the device.
>>>
>>> Maybe it was asked before, but what qmicli version are you using?
>> It is version 1.22.2.
>>
>> There is no change when adding --set-expected-data-format.  Below is
>> the
>> log:
> Can you run:
>
> qmicli -d /dev/cdc-wdm0 --wds-get-profile-list=3gpp
qmicli -d /dev/cdc-wdm0 --wds-get-profile-list=3gpp
Profile list retrieved:
         [1] 3gpp - profile1
                 APN: ''
                 PDP type: 'ipv4-or-ipv6'
                 PDP context number: '1'
                 Username: ''
                 Password: ''
                 Auth: 'none'
                 APN disabled: 'no'
> qmicli -d /dev/cdc-wdm0 --wds-get-default-settings=3gpp
qmicli -d /dev/cdc-wdm0 --wds-get-default-settings=3gpp
Default settings retrieved:
         APN: ''
         PDP type: 'ipv4-or-ipv6'
         Username: ''
         Password: ''

         Auth: 'none'


Oooohhhhh! That'll be damned. No APN string. Meaning that when 
autoconnect triggered in-between the manual attempts, it would connect, 
while manual attempts with APN=internet failed...!? The APN=internet 
settings has been there for years on these systems. That's what you get 
from taking over code from others, and assuming settings are right... ! :D

Does that sound reasonable as the explanation?

>
> Dan
>
>> Btw, the Linux kernel is compiled without IPv6 on this system. That
>> is
>> why we have specfied ip-type=4. But maybe it is still related to the
>> kernel not supporting v6 here?
>>
>> # Checking that we are not connected and that autoconnect is not
>> enabled
>> $ qmicli -d /dev/cdc-wdm0 --wds-get-packet-service-status
>> [/dev/cdc-wdm0] Connection status: 'disconnected'
>> $ qmicli -d /dev/cdc-wdm0 --wds-get-autoconnect-settings
>> Autoconnect settings retrieved:
>>           Status: 'disabled'
>>           Roaming: 'allowed'
>> # Seems OK
>>
>> # Settings expected data format
>> $ qmicli -d /dev/cdc-wdm0 --set-expected-data-format=802-3
>> [/dev/cdc-wdm0] expected data format set to: 802-3
>>
>> # Check which data format we have
>> $  qmicli -d /dev/cdc-wdm0 --wda-get-data-format
>> [/dev/cdc-wdm0] Successfully got data format
>>                      QoS flow header: no
>>                  Link layer protocol: 'raw-ip'
>>     Uplink data aggregation protocol: 'disabled'
>> Downlink data aggregation protocol: 'disabled'
>>                        NDP signature: '0'
>>     Uplink data aggregation max size: '0'
>> Downlink data aggregation max size: '0'
>>
>> # Change to 802-3
>> $  qmicli -d /dev/cdc-wdm0 --wda-set-data-format=802-3
>> [/dev/cdc-wdm0] Successfully set data format
>>                           QoS flow header: no
>>                       Link layer protocol: '802-3'
>>          Uplink data aggregation protocol: 'disabled'
>>        Downlink data aggregation protocol: 'disabled'
>>                             NDP signature: '0'
>> Downlink data aggregation max datagrams: '0'
>>        Downlink data aggregation max size: '0'
>>
>> # Seemed to work.
>> # Just check again to be sure
>> $ qmicli -d /dev/cdc-wdm0 --wda-get-data-format
>> [/dev/cdc-wdm0] Successfully got data format
>>                      QoS flow header: no
>>                  Link layer protocol: '802-3'
>>     Uplink data aggregation protocol: 'disabled'
>> Downlink data aggregation protocol: 'disabled'
>>                        NDP signature: '0'
>>     Uplink data aggregation max size: '0'
>> Downlink data aggregation max size: '0'
>>
>> # Start the network manually
>> $ qmicli -v -d /dev/cdc-wdm0 --wds-start-network=apn=internet,ip-
>> type=4
>> --client-no-release-cid
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] Opening device with
>> flags 'auto'...
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] loaded driver of cdc-
>> wdm
>> port: qmi_wwan
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] automatically
>> selecting
>> QMI mode
>> [15 Apr 2020, 08:40:59] [Debug] QMI Device at '/dev/cdc-wdm0' ready
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] Assuming service
>> 'wds'
>> is supported...
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] Allocating new client
>> ID...
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] sent message...
>> <<<<<< RAW:
>> <<<<<<   length = 16
>> <<<<<<   data   = 01:0F:00:00:00:00:00:01:22:00:04:00:01:01:00:01
>>
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] sent generic request
>> (translated)...
>> <<<<<< QMUX:
>> <<<<<<   length  = 15
>> <<<<<<   flags   = 0x00
>> <<<<<<   service = "ctl"
>> <<<<<<   client  = 0
>> <<<<<< QMI:
>> <<<<<<   flags       = "none"
>> <<<<<<   transaction = 1
>> <<<<<<   tlv_length  = 4
>> <<<<<<   message     = "Allocate CID" (0x0022)
>> <<<<<< TLV:
>> <<<<<<   type       = "Service" (0x01)
>> <<<<<<   length     = 1
>> <<<<<<   value      = 01
>> <<<<<<   translated = wds
>>
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] received message...
>> <<<<<< RAW:
>> <<<<<<   length = 24
>> <<<<<<   data   =
>> 01:17:00:80:00:00:01:01:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:01:
>> 09
>>
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] received generic
>> response (translated)...
>> <<<<<< QMUX:
>> <<<<<<   length  = 23
>> <<<<<<   flags   = 0x80
>> <<<<<<   service = "ctl"
>> <<<<<<   client  = 0
>> <<<<<< QMI:
>> <<<<<<   flags       = "response"
>> <<<<<<   transaction = 1
>> <<<<<<   tlv_length  = 12
>> <<<<<<   message     = "Allocate CID" (0x0022)
>> <<<<<< TLV:
>> <<<<<<   type       = "Result" (0x02)
>> <<<<<<   length     = 4
>> <<<<<<   value      = 00:00:00:00
>> <<<<<<   translated = SUCCESS
>> <<<<<< TLV:
>> <<<<<<   type       = "Allocation Info" (0x01)
>> <<<<<<   length     = 2
>> <<<<<<   value      = 01:09
>> <<<<<<   translated = [ service = 'wds' cid = '9' ]
>>
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] Registered 'wds'
>> (version unknown) client with ID '9'
>> [15 Apr 2020, 08:40:59] [Debug] Network start parameters set (apn:
>> 'internet', 3gpp_profile: '0', 3gpp2_profile: '0', auth:
>> 'unspecified',
>> ip-type: '4', username: 'unspecified', password: 'unspecified',
>> autoconnect: 'unspecified')
>> [15 Apr 2020, 08:40:59] [Debug] Asynchronously starting network...
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] sent message...
>> <<<<<< RAW:
>> <<<<<<   length = 28
>> <<<<<<   data   =
>> 01:1B:00:00:01:09:00:01:00:20:00:0F:00:19:01:00:04:14:08:00:69:6E:74:
>> 65:72:6E:65:74
>>
>> [15 Apr 2020, 08:40:59] [Debug] [/dev/cdc-wdm0] sent generic request
>> (translated)...
>> <<<<<< QMUX:
>> <<<<<<   length  = 27
>> <<<<<<   flags   = 0x00
>> <<<<<<   service = "wds"
>> <<<<<<   client  = 9
>> <<<<<< QMI:
>> <<<<<<   flags       = "none"
>> <<<<<<   transaction = 1
>> <<<<<<   tlv_length  = 15
>> <<<<<<   message     = "Start Network" (0x0020)
>> <<<<<< TLV:
>> <<<<<<   type       = "IP Family Preference" (0x19)
>> <<<<<<   length     = 1
>> <<<<<<   value      = 04
>> <<<<<<   translated = ipv4
>> <<<<<< TLV:
>> <<<<<<   type       = "APN" (0x14)
>> <<<<<<   length     = 8
>> <<<<<<   value      = 69:6E:74:65:72:6E:65:74
>> <<<<<<   translated = internet
>>
>> [15 Apr 2020, 08:41:01] [Debug] [/dev/cdc-wdm0] received message...
>> <<<<<< RAW:
>> <<<<<<   length = 32
>> <<<<<<   data   =
>> 01:1F:00:80:01:09:02:01:00:20:00:13:00:02:04:00:01:00:0E:00:10:02:00:
>> 03:00:11:04:00:02:00:D2:00
>>
>> [15 Apr 2020, 08:41:01] [Debug] [/dev/cdc-wdm0] received generic
>> response (translated)...
>> <<<<<< QMUX:
>> <<<<<<   length  = 31
>> <<<<<<   flags   = 0x80
>> <<<<<<   service = "wds"
>> <<<<<<   client  = 9
>> <<<<<< QMI:
>> <<<<<<   flags       = "response"
>> <<<<<<   transaction = 1
>> <<<<<<   tlv_length  = 19
>> <<<<<<   message     = "Start Network" (0x0020)
>> <<<<<< TLV:
>> <<<<<<   type       = "Result" (0x02)
>> <<<<<<   length     = 4
>> <<<<<<   value      = 01:00:0E:00
>> <<<<<<   translated = FAILURE: CallFailed
>> <<<<<< TLV:
>> <<<<<<   type       = "Call End Reason" (0x10)
>> <<<<<<   length     = 2
>> <<<<<<   value      = 03:00
>> <<<<<<   translated = generic-no-service
>> <<<<<< TLV:
>> <<<<<<   type       = "Verbose Call End Reason" (0x11)
>> <<<<<<   length     = 4
>> <<<<<<   value      = 02:00:D2:00
>> <<<<<<   translated = [ type = 'internal' reason = '210' ]
>>
>> error: couldn't start network: QMI protocol error (14): 'CallFailed'
>> call end reason (3): generic-no-service
>> verbose call end reason (2,210): [internal] pdn-ipv6-call-disallowed
>> [/dev/cdc-wdm0] Client ID not released:
>>           Service: 'wds'
>>               CID: '9'
>> [15 Apr 2020, 08:41:01] [Debug] [/dev/cdc-wdm0] Releasing 'wds'
>> client
>> with flags 'none'...
>> [15 Apr 2020, 08:41:01] [Debug] [/dev/cdc-wdm0] Unregistered 'wds'
>> client with ID '9'
>> [15 Apr 2020, 08:41:01] [Debug] Client released
>> [15 Apr 2020, 08:41:01] [Debug] Closed
>> # Failed with exit code 1 and no handle returned
>>
>>
>>>> Btw, we also tried the qmi-network script, which fails similarly:
>>>>
>>>> $ qmi-network /dev/cdc-wdm0 start
>>>> Loading profile at /etc/qmi-network.conf...
>>>>        APN: internet
>>>>        APN user: unset
>>>>        APN password: unset
>>>>        qmi-proxy: yes
>>>> Checking data format with 'qmicli -d /dev/cdc-wdm0 --wda-get-
>>>> data-
>>>> format
>>>> --device-open-proxy'...
>>>> Device link layer protocol retrieved: raw-ip
>>>> Getting expected data format with 'qmicli -d /dev/cdc-wdm0
>>>> --get-expected-data-format'...
>>>> Expected link layer protocol retrieved: 802-3
>>>> Updating kernel link layer protocol with 'qmicli -d /dev/cdc-wdm0
>>>> --set-expected-data-format=raw-ip'...
>>>> error: cannot set expected data format: Expected data format not
>>>> updated
>>>> properly to 'raw-ip': got '802-3' instead
>>>> Error updating kernel link layer protocol
>>>> Starting network with 'qmicli -d /dev/cdc-wdm0
>>>> --wds-start-network=apn='internet'  --client-no-release-cid
>>>> --device-open-proxy'...
>>>> error: couldn't start network: QMI protocol error (14):
>>>> 'CallFailed'
>>>> call end reason (3): generic-no-service
>>>> verbose call end reason (2,210): [internal] pdn-ipv6-call-
>>>> disallowed
>>>> Saving state at /tmp/qmi-network-state-cdc-wdm0... (CID: 9)
>>>> error: network start failed, no packet data handle
>>>> Clearing state at /tmp/qmi-network-state-cdc-wdm0...
>>>>
>>>> Best regards,
>>>>
>>>> *Tor Rune Skoglund*
>>>>
>>>>
>>>> Den 08.04.2020 17:45, skrev Aleksander Morgado:
>>>>> Hey,
>>>>>
>>>>>> tir. 7. apr. 2020 kl. 17:17 skrev Aleksander Morgado <
>>>>>> aleksander at aleksander.es>:
>>>>>>>> I have some further updates here. I read another thread
>>>>>>>> about
>>>>>>>> the '-p' option,
>>>>>>>> which, when added to all instances of qmicli invocation
>>>>>>>> in
>>>>>>>> the init.d file makes
>>>>>>>> the problem go away in at least more than 9 out of 10
>>>>>>>> cases.
>>>>>>>> So it is
>>>>>>>> apparently a timing issue. Still have to test this on
>>>>>>>> more
>>>>>>>> than one
>>>>>>>> system, but I am optimistic. :)
>>>>>>> The "-p" option, if used, must be used in ALL qmicli
>>>>>>> commands,
>>>>>>> so that
>>>>>>> all use the intermediate qmi-proxy.
>>>>>>> I wonder what init.d file you're talking about, though?
>>>>>> We initialise the modem with this routine (somewhat
>>>>>> simplified to
>>>>>> illustrate the points):
>>>>>>
>>>>>> START_NETWORK_ARGS=apn="internet",ip-type=4,autoconnect=yes
>>>>>>
>>>>>> #QMICMD='qmicli -p '
>>>>>> QMICMD='qmicli '
>>>>>>
>>>>>> for DEV in $(find /dev -maxdepth 1 -name "cdc-wdm*" | sort)
>>>>>> do
>>>>>>        WANIF=$($QMICMD -d "$DEV" -w)
>>>>>>        if $QMICMD -d "$DEV" --wds-get-packet-service-status |
>>>>>> grep
>>>>>> -q status:..connected ; then
>>>>>>            echo "Stopping as it was already connected $DEV
>>>>>> $WANIF"
>>>>>>            $QMICMD -d "$DEV" --wds-stop-network=disable-
>>>>>> autoconnect
>>>>> That above is not a good way to disconnect if you're manually
>>>>> running
>>>>> Start Network, see other comments below.
>>>>>
>>>>>>            ip link set "$WANIF" down 2>&1
>>>>>>            ip addr flush dev "$WANIF" 2>&1
>>>>>>            echo "Stopped broadband on $DEV $WANIF to restart
>>>>>> connection"
>>>>>>        fi
>>>>>>
>>>>>>        # Does it work at all....?
>>>>>>        if ! $QMICMD -d "$DEV" --wda-get-data-format ; then
>>>>>>            echo "Modem does not respond as expected - trying
>>>>>> to
>>>>>> reset it"
>>>>>>            # Here we had some code to try various things to
>>>>>> get it
>>>>>> working, like resetting the usb port it is connected to.
>>>>>>            # However, following commands could still fail
>>>>>>        fi
>>>>>>
>>>>>>        # Change to 802-3
>>>>>>        if $QMICMD -d "$DEV" --wda-get-data-format | grep -q
>>>>>> 'raw-
>>>>>> ip'; then
>>>>>>            echo "Identified $DEV $WANIF as raw-ip, changing to
>>>>>> 802-
>>>>>> 3"
>>>>>>            if ! $QMICMD -d "$DEV" --wda-set-data-format=802-3
>>>>>> ;
>>>>>> then
>>>>>>                echo "wda-set-data-format=802-3 failed"
>>>>> You cannot change data format after having started the
>>>>> connection.
>>>>> In
>>>>> the logic below you're connecting in 2 different ways (start
>>>>> network
>>>>> with apn, and autoconnect), but you're only stopping in one way
>>>>> (autoconnect). It may happen that the set data format fails
>>>>> because
>>>>> the modem is already connected?
>>>>>
>>>>>>                exit 1
>>>>>>            fi
>>>>>>        else
>>>>>>            echo "Failed to set $DEV $WANIF data format to 802-
>>>>>> 3"
>>>>>>        fi
>>>>>>
>>>>>>        # Set up if correct mode
>>>>>>        if ! $QMICMD -d "$DEV" --wda-get-data-format | grep -q
>>>>>> '802-
>>>>>> 3'; then
>>>>>>            echo "Modem is not is correct data format mode"
>>>>> Don't rely on devices supporting all 802.3. All new QMI devices
>>>>> don't
>>>>> support 802.3, they only support raw-ip. If you're stuck with
>>>>> an
>>>>> older
>>>>> model, this may be enough though, so just a heads up.
>>>>>
>>>>>>            exit 1
>>>>>>        fi
>>>>>>        echo "Starting broadband on $DEV $WANIF with args
>>>>>> '$START_NETWORK_ARGS'"
>>>>>>        $QMICMD -d "$DEV" --wds-start-
>>>>>> network=${START_NETWORK_ARGS:-
>>>>>> apn=\"internet\"} --client-no-release-cid
>>>>>>        $QMICMD -d "$DEV" --wds-set-autoconnect-
>>>>>> settings=enabled,roaming-allowed
>>>>> You're attempting to manually connect with start network and
>>>>> then
>>>>> enabling autoconnect, and that doesn't make sense, these are 2
>>>>> different things. Autoconnect will use the "default 3GPP"
>>>>> profile
>>>>> settings, and the manual start network will try to use whatever
>>>>> settings you're passing. You should either use one approach or
>>>>> the
>>>>> other, using both won't work properly I believe.
>>>>>
>>>>> Also, if you run start network manually, you need to keep track
>>>>> of
>>>>> the
>>>>> CID you used to connect, and also track of the "connection id"
>>>>> returned by the command, so that you can then perform the
>>>>> associated
>>>>> stop network passing the correct cid and the correct connection
>>>>> id.
>>>>>
>>>>>>        echo "Started broadband on $DEV $WANIF"
>>>>>>        killall -HUP dhcpcd
>>>>>>        exit 0 # Done
>>>>>> done
>>>>>>
>>>>>> einfo "Failed to set up broadband adapter"
>>>>>> exit 1 # Failed
>>>>>>
>>>>>> If I use -p it seems to work close to 100% (maybe 100% of the
>>>>>> times). Without the script fails too often on the first wda-
>>>>>> get-
>>>>>> data-format.
>>>>>>
>>>>>> (Btw, --wds-start-network also gives an error, but it does
>>>>>> not
>>>>>> seem to affect anything:
>>>>>> qmicli -p -d /dev/cdc-wdm0 --wds-start-
>>>>>> network=apn=internet,ip-
>>>>>> type=4,autoconnect=yes --client-no-release-cid
>>>>>> error: couldn't start network: QMI protocol error (14):
>>>>>> 'CallFailed'
>>>>>> call end reason (3): generic-no-service
>>>>>> verbose call end reason (2,210): [internal] pdn-ipv6-call-
>>>>>> disallowed
>>>>>> [/dev/cdc-wdm0] Client ID not released:
>>>>>>           Service: 'wds'
>>>>>>               CID: '9')
>>>>> If start network fails, but anyway you're connected it means
>>>>> the
>>>>> modem
>>>>> may be setup to autoconnect using the default 3GPP profile (see
>>>>> qmicli
>>>>> --wds-get-profile-list=3gpp and qmicli
>>>>> --wds-get-default-profile-num=3gpp). So it is not that it
>>>>> doesn't
>>>>> affect anything, it's that you may be trying to connect with
>>>>> different
>>>>> settings to the default ones, and the settings you used
>>>>> explicitly
>>>>> are
>>>>> failing.
>>>>>
>>>>>> Actually, while writing this mail, I made a new discovery: It
>>>>>> looks like if  -wda-get-data-format fails once, for example
>>>>>> when
>>>>>> running it first without -p, it will keep on failing, even if
>>>>>> run
>>>>>> with -p later. However, a usb port reset (unbind/bind) will
>>>>>> make
>>>>>> it work again if I then run with -p directly afterwards.
>>>>>>
>>>>>> I have very few clues on what is going on. It could very well
>>>>>> be
>>>>>> that we are doing something wrong....(?)
>>>>>>
>>>>> The use of "-p" just makes all your qmicli requests be
>>>>> forwarded to
>>>>> the device through an intermediate qmi-proxy process. This is
>>>>> done
>>>>> so
>>>>> that multiple applications can use the port at the same time
>>>>> for
>>>>> different commands; either multiple qmicli calls or even
>>>>> different
>>>>> programs doing different QMI interactions. E.g. you can use the
>>>>> "Mobile Radio Monitor" program
>>>>> (https://sigquit.wordpress.com/2013/09/17/mobile-radio-monitor/
>>>>> ) at
>>>>> the same time as ModemManager is managing the device because
>>>>> both
>>>>> programs use the intermediate proxy. If there is one program
>>>>> using
>>>>> the
>>>>> proxy, all programs must use it.
>>>>>
>>>>> If some programs use it and some others don't, the ones not
>>>>> using
>>>>> it
>>>>> will all fight each other with the qmi-proxy for the access to
>>>>> the
>>>>> QMI
>>>>> control port.
>>>>>
>>>>> If you're on doubt on what to do, just use the proxy always
>>>>> always,
>>>>> and never attempt a qmicli command without using the proxy, as
>>>>> that
>>>>> will break the comm between the device and the proxy. So, the
>>>>> tests
>>>>> sometimes trying with "-p" and sometimes without "-p" don't
>>>>> really
>>>>> make sense because the testing itself is breaking the flow.
>>>>>
>>>>> Also, a lot of this logic is already handled in the qmi-network
>>>>> script, I'd suggest you take a look at its source code, it's
>>>>> quite
>>>>> simple.
>>>>>
>>>>> Cheers!
>>>>>
>>>> _______________________________________________
>>>> libqmi-devel mailing list
>>>> libqmi-devel at lists.freedesktop.org
>>>> https://lists.freedesktop.org/mailman/listinfo/libqmi-devel
>> _______________________________________________
>> libqmi-devel mailing list
>> libqmi-devel at lists.freedesktop.org
>> https://lists.freedesktop.org/mailman/listinfo/libqmi-devel
> _______________________________________________
> libqmi-devel mailing list
> libqmi-devel at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/libqmi-devel


More information about the libqmi-devel mailing list