Thingy91: pynrfjprog deadlocks at 100% cpu usage

[Triffid_Hunter]

I'm using the script from https://devzone.nordicsemi.com/f/nordic-q-a/53208/updating-nrf9160-modem-firmware-through-the-command-line/215357#215357

Under strace, it never forks any other process and doesn't create the file it's looking for, so I'm really not sure what it's expecting to happen.

Full strace at http://triffid-hunter.no-ip.info/pynrf-flash.strace since this forum thing keeps throwing errors when I try to attach it.

https://devzone.nordicsemi.com/f/nordic-q-a/62397/nrfjprog-bug-gets-stuck-due-to-temporary-directory-permissions seems related however my permissions are fine, and the directory tree in /tmp is recreated identically if I wipe it first.

Since this is apparently the only way to update the NRF91 modem firmware from a terminal, and all the examples seem to be complaining about out-of-date modem firmware, I'm once again stuck.

[Håkon Alseth]

Hi,

 

Unfortunately, this is a bug that we recently found in pynrfjprog. We are working on fixing this, but its not yet ready for release.

My apologies for the inconvenience this has caused.

 

Is it possible that you can use nRF connect for desktop (programmer app, works on *nix + win) to upgrade the modem on this device?

 

Kind regards,

Håkon

[Triffid_Hunter]

Håkon Alseth said:

Is it possible that you can use nRF connect for desktop (programmer app, works on *nix + win) to upgrade the modem on this device?

Not until https://devzone.nordicsemi.com/f/nordic-q-a/64132/nordic-thingy91-error-updating-modem-firmware is fixed for Linux, and since I have a very strong penchant for Makefiles and command-line tools (since I enjoy hands-off automation and CI) that would only ever be an unsustainable kludge for me.

How usable are the tools mentioned in https://devzone.nordicsemi.com/f/nordic-q-a/14671/nrfjprog-for-arm-cpu-raspberry-pi-3 these days?

[Håkon Alseth]

Hi,

 

Triffid_Hunter said:

How usable are the tools mentioned in https://devzone.nordicsemi.com/f/nordic-q-a/14671/nrfjprog-for-arm-cpu-raspberry-pi-3 these days?

that is a shell script on top of JLinkExe, which does not have support for programming a nRF9160 modem, unfortunately. You can use it to program the application (JLinkExe -> loadfile <hex>), but not the modem.

 

Triffid_Hunter said:

Not until https://devzone.nordicsemi.com/f/nordic-q-a/64132/nordic-thingy91-error-updating-modem-firmware is fixed for Linux, and since I have a very strong penchant for Makefiles and command-line tools (since I enjoy hands-off automation and CI) that would only ever be an unsustainable kludge for me.

That case is related to using mcuboot for upgrading the modem (ie: a USB CDC device) on the thingy:91, and most of the errors in that case is related to either non-installed JLink binaries / nrfjprog binaries, or path problems towards one or both of these. I'm not excluding issues with other distros, but its more likely that its deps or path related.

I tried the sequence for mcuboot-upgrade-of-modem + programming it standalone using the nrf connect v3.4.2 - programmer app, and both are working in ubuntu 20.04 amd64. If you get an error message when trying this procedure either via thingy:91's mcuboot or via an external debugger, please share it with me and I'll try to help out.

 

Kind regards,

Håkon

[Triffid_Hunter]

Just FYI, amazon is throwing 403 errors at your client when it tries to do partial updates.

13:05:22.626 › Checking for update
13:05:42.052 › Found version 3.4.2 (url: nrfconnect-3.4.2-x86_64.AppImage)
13:05:47.330 › Downloading update from nrfconnect-3.4.2-x86_64.AppImage
13:05:47.349 › updater cache dir: /home/triffid/.cache/nrfconnect-updater
13:05:47.363 › No cached update info available
13:07:08.977 › dkTihOXnG2ovqMEkpxwLPI+I duplicated in blockmap (same size), it doesn't lead to broken differential downloader, just corresponding block will be skipped)
13:07:08.977 › JRb1UK4Z/x76FrzcLRE0UX6J duplicated in blockmap (same size), it doesn't lead to broken differential downloader, just corresponding block will be skipped)
13:07:08.977 › oqYY7uJtPGEu9GT1URW/ZIZc duplicated in blockmap (same size), it doesn't lead to broken differential downloader, just corresponding block will be skipped)
13:07:08.977 › gRW5vkI5NXYlu2aP5yoTNMeY duplicated in blockmap (same size), it doesn't lead to broken differential downloader, just corresponding block will be skipped)
13:07:08.977 › 9LuhCEOQzb8vn0X29vVoEb83 duplicated in blockmap (same size), it doesn't lead to broken differential downloader, just corresponding block will be skipped)
13:07:08.977 › o6Hp7Jg7kvy5lZV89L6QRBa7 duplicated in blockmap (same size), it doesn't lead to broken differential downloader, just corresponding block will be skipped)
13:07:08.977 › /L8C1zeBidj9/kArl4fnYFM5 duplicated in blockmap (same size), it doesn't lead to broken differential downloader, just corresponding block will be skipped)
13:07:08.978 › tSaId5LMeXrZEioF0oMGS+Z7 duplicated in blockmap (same size), it doesn't lead to broken differential downloader, just corresponding block will be skipped)
13:07:08.978 › br2FvDMSa6Bk8w6LNGa/5RFf duplicated in blockmap (same size), it doesn't lead to broken differential downloader, just corresponding block will be skipped)
13:07:08.979 › File has 1302 changed blocks
13:07:08.979 › [
{
"kind": 0,
"start": 0,
"end": 159006
},
{
"kind": 1,
"start": 159006,
"end": 191774
},
{
"kind": 0,
"start": 191774,
"end": 59020876
},
{
"kind": 1,
"start": 59020876,
"end": 59032521
},
{
"kind": 0,
"start": 59032522,
"end": 66092751
},
{
"kind": 1,
"start": 66092750,
"end": 66813059
},
{
"kind": 0,
"start": 66812143,
"end": 66829834
},
{
"kind": 1,
"start": 66830750,
"end": 67114423
},
{
"kind": 0,
"start": 67113436,
"end": 67124550
},
{
"kind": 1,
"start": 67125537,
"end": 67323400
},
{
"kind": 0,
"start": 88126999,
"end": 88137299
},
{
"kind": 1,
"start": 67333700,
"end": 67509636
},
{
"kind": 0,
"start": 67508589,
"end": 67630889
},
{
"kind": 1,
"start": 67631936,
"end": 67653730
},
{
"kind": 0,
"start": 67652683,
"end": 67661468
},
{
"kind": 1,
"start": 67662515,
"end": 74477772
},
{
"kind": 0,
"start": 66812143,
"end": 66853473
},
{
"kind": 1,
"start": 74519102,
"end": 74660620
},
{
"kind": 0,
"start": 74640545,
"end": 74650179
},
{
"kind": 1,
"start": 74670254,
"end": 86724996
},
{
"kind": 0,
"start": 66683393,
"end": 66693181
},
{
"kind": 1,
"start": 86734784,
"end": 93452268
},
{
"kind": 0,
"start": 92925548,
"end": 100429017
},
{
"kind": 1,
"start": 100955737,
"end": 100990952
}
]
13:07:08.990 › Full: 98,728.24 KB, To download: 26,570.51 KB (27%)
13:07:08.992 › Differential download: github.com/.../nrfconnect-3.4.2-x86_64.AppImage
13:07:08.995 › download range: bytes=159006-191773
13:07:09.680 › Redirect to github-production-release-asset-2e65be.s3.amazonaws.com/.../ca45de00-d7cf-11ea-856e-beed2fafbb84
13:07:17.848 › download range: bytes=59020876-59032520
13:07:19.483 › download range: bytes=66092750-66813058
13:29:14.325 › download range: bytes=66830750-67114422
13:29:14.957 › Cannot download differentially, fallback to full download: HttpError: 403 Forbidden
Headers: {
"connection": [
"close"
],
"content-type": [
"application/xml"
],
"date": [
"Wed, 12 Aug 2020 05:29:14 GMT"
],
"server": [
"AmazonS3"
],
"transfer-encoding": [
"chunked"
],
"x-amz-id-2": [
"MJwp4R8UJc4aCwKW4b828qX1sqOVxulGmzRPJIcrpu94JbavvDoGYS5o2h0Ix6Ke96eZ6nWlYTU="
],
"x-amz-request-id": [
"8C1F1693119B1923"
]
}
at createHttpError (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/builder-util-runtime/src/httpExecutor.ts:30:10)
at ClientRequest.<anonymous> (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/differentialDownloader/DifferentialDownloader.ts:200:20)
at ClientRequest.emit (events.js:194:13)
at URLRequest.<anonymous> (/tmp/.mount_nrfconNHk6h0/resources/electron.asar/browser/api/net.js:207:12)
at URLRequest.emit (events.js:194:13)
From previous event:
at /tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/graceful-fs/graceful-fs.js:333:16
at FSReqCallback.oncomplete (fs.js:150:20)
From previous event:
at FileWithEmbeddedBlockMapDifferentialDownloader.doDownloadFile (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/differentialDownloader/DifferentialDownloader.ts:115:82)
at FileWithEmbeddedBlockMapDifferentialDownloader.downloadFile (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/differentialDownloader/DifferentialDownloader.ts:89:17)
at FileWithEmbeddedBlockMapDifferentialDownloader.doDownload (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/differentialDownloader/DifferentialDownloader.ts:76:17)
at /tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/differentialDownloader/FileWithEmbeddedBlockMapDifferentialDownloader.ts:14:16
From previous event:
at FileWithEmbeddedBlockMapDifferentialDownloader.download (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/differentialDownloader/FileWithEmbeddedBlockMapDifferentialDownloader.ts:8:17)
at Object.<anonymous> (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/AppImageUpdater.ts:53:14)
at Generator.next (<anonymous>)
From previous event:
at Object.task (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/AppImageUpdater.ts:37:11)
at /tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/AppUpdater.ts:609:25
at Generator.next (<anonymous>)
at processImmediate (internal/timers.js:443:21)
From previous event:
at AppImageUpdater.executeDownload (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/AppUpdater.ts:544:68)
at AppImageUpdater.executeDownload (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/BaseUpdater.ts:27:18)
at AppImageUpdater.doDownloadUpdate (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/AppImageUpdater.ts:33:17)
at AppImageUpdater.downloadUpdate (/tmp/.mount_nrfconNHk6h0/resources/app.asar/node_modules/electron-updater/src/AppUpdater.ts:419:19)
at callFunction (/tmp/.mount_nrfconNHk6h0/resources/electron.asar/browser/rpc-server.js:252:24)
at /tmp/.mount_nrfconNHk6h0/resources/electron.asar/browser/rpc-server.js:411:10
at EventEmitter.<anonymous> (/tmp/.mount_nrfconNHk6h0/resources/electron.asar/browser/rpc-server.js:275:21)
at EventEmitter.emit (events.js:194:13)
at WebContents.<anonymous> (/tmp/.mount_nrfconNHk6h0/resources/electron.asar/browser/api/web-contents.js:418:21)
at WebContents.emit (events.js:194:13)

I've been waiting a couple hours for it to finish the full download and it's still going - perhaps you should put a progress bar and some numbers in the client?

[Triffid_Hunter]

Same error with latest version of nRF connect and updated programmer:

2020-08-12T07:54:14.478Z INFO Application data folder: /home/triffid/.config/nrfconnect/pc-nrfconnect-programmer
2020-08-12T07:54:14.574Z DEBUG App pc-nrfconnect-programmer v1.4.4 official
2020-08-12T07:54:14.574Z DEBUG App path: /home/triffid/.nrfconnect-apps/node_modules/pc-nrfconnect-programmer
2020-08-12T07:54:14.575Z DEBUG nRFConnect 3.4.2 is supported by the app (^3.3.0)
2020-08-12T07:54:14.575Z DEBUG nRFConnect path: /tmp/.mount_nrfconlNUQmN/resources/app.asar
2020-08-12T07:54:14.575Z DEBUG HomeDir: /home/triffid
2020-08-12T07:54:14.575Z DEBUG TmpDir: /tmp
2020-08-12T07:54:14.582Z INFO Using nrfjprog library 10.9.0, pc-nrfjprog-js 1.7.3
2020-08-12T07:54:14.612Z ERROR Error while probing devices: Error occured when get serial numbers. Errorcode: CouldNotCallFunction (0x9)
Lowlevel error: INVALID_OPERATION (fffffffe)

2020-08-12T07:54:25.278Z INFO Modem DFU starts to write...
2020-08-12T07:54:25.279Z INFO Writing /home/triffid/Projects/NRF/thingy91_fw_2020-04-29_bc7ade8b/mfwnrf9160120.zip to device
2020-08-12T07:54:25.719Z ERROR MCUboot DFU failed. Please make sure that the device is in MCUboot mode and try again.

I followed the instructions wrt holding SW3 during poweron to access MCUBoot mode, although this doesn't seem to make any difference to the USB descriptors that it delivers:

$ lsusb -d 1915:520f -v

Bus 001 Device 026: ID 1915:520f Nordic Semiconductor ASA Weltrend USB Mouse
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass          239 Miscellaneous Device
  bDeviceSubClass         2
  bDeviceProtocol         1 Interface Association
  bMaxPacketSize0        64
  idVendor           0x1915 Nordic Semiconductor ASA
  idProduct          0x520f
  bcdDevice            0.11
  iManufacturer           1 Nordic Semiconductor
  iProduct                2 Thingy:91 UART
  iSerial                 3 PCA20035_e7cec1bcfe84
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x008d
    bNumInterfaces          4
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0xe0
      Self Powered
      Remote Wakeup
    MaxPower              100mA
    Interface Association:
      bLength                 8
      bDescriptorType        11
      bFirstInterface         0
      bInterfaceCount         2
      bFunctionClass          2 Communications
      bFunctionSubClass       2 Abstract (modem)
      bFunctionProtocol       0
      iFunction               0
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         2 Communications
      bInterfaceSubClass      2 Abstract (modem)
      bInterfaceProtocol      0
      iInterface              0
      CDC Header:
        bcdCDC               1.10
      CDC Call Management:
        bmCapabilities       0x02
          use DataInterface
        bDataInterface          1
      CDC ACM:
        bmCapabilities       0x02
          line coding and serial state
      CDC Union:
        bMasterInterface        0
        bSlaveInterface         1
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0010  1x 16 bytes
        bInterval              10
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        1
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass        10 CDC Data
      bInterfaceSubClass      0
      bInterfaceProtocol      0
      iInterface              0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x82  EP 2 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x01  EP 1 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               0
    Interface Association:
      bLength                 8
      bDescriptorType        11
      bFirstInterface         2
      bInterfaceCount         2
      bFunctionClass          2 Communications
      bFunctionSubClass       2 Abstract (modem)
      bFunctionProtocol       0
      iFunction               0
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        2
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         2 Communications
      bInterfaceSubClass      2 Abstract (modem)
      bInterfaceProtocol      0
      iInterface              0
      CDC Header:
        bcdCDC               1.10
      CDC Call Management:
        bmCapabilities       0x02
          use DataInterface
        bDataInterface          1
      CDC ACM:
        bmCapabilities       0x02
          line coding and serial state
      CDC Union:
        bMasterInterface        2
        bSlaveInterface         3
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x83  EP 3 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0010  1x 16 bytes
        bInterval              10
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        3
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass        10 CDC Data
      bInterfaceSubClass      0
      bInterfaceProtocol      0
      iInterface              0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x84  EP 4 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x02  EP 2 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               0
Device Status:     0x0000
  (Bus Powered)

I tried numerous times, both with and without SW3 held to no avail.

[Triffid_Hunter]

I've also tried using a JLink, but nRF Connect Programmer won't recognise it, claiming "ERROR Unsupported device. The detected device could not be recognized as neither JLink device nor Nordic USB device." even though it works fine with nrfjprog :-

$ nrfjprog --deviceversion
NRF9160_xxAA_REV2

[Triffid_Hunter]

I ran nRF Connect programmer under strace to see what it's doing when I try to update modem firmware, doesn't look like it's doing much at all with the serial port - opens the port, writes a few bytes, hands it off to another process which waits a moment then quits.

strace log here: triffid-hunter.no-ip.info/nrfc.strace.gz (gzipped because it's 47MB uncompressed) - ACM0 is opened at line 424297.

[Håkon Alseth]

Hi,

 

Is this the JLink version you're using?

JLink_Linux_V630h_x86_64

 

If that is the case, could you please update to a newer version? This one is quite old, and does not include support for nrf9160 (Cortex m33). You can download a bundle from here: https://www.nordicsemi.com/Software-and-tools/Development-Tools/nRF-Command-Line-Tools/Download#infotabs

 

Did you update over ttyACMx in this trace log? Could you attach the error code when trying to connect using a standard swd debugger? a screenshot would suffice.

 

Kind regards,

Håkon

[Triffid_Hunter]

Håkon Alseth said:

Is this the JLink version you're using?

JLink_Linux_V630h_x86_64

nrfjprog -v says nrfjprog version: 10.9.0, JLinkARM.dll version: 6.80a

Håkon Alseth said:

Did you update over ttyACMx in this trace log? Could you attach the error code when trying to connect using a standard swd debugger? a screenshot would suffice.

[Triffid_Hunter]

Hi Håkon,

We had one of Nordic's FAEs (George Xiong) come over today to have a poke at things here.

He brought a couple of NRF9160-DKs with him, and the NRF Connect app says the same thing (Unsupported device. The detected device could not be recognized as neither JLink device nor Nordic USB device) even with the official DK plugged in to my machine.

nrfjprog recognised it (and the nrf9160) just fine, but apparently nrfjprog can't flash modem firmware.

He was unfamiliar with the pynrfjprog library and thus unable to help make any progress there.

His computer was also unable to flash the modem firmware, but we scavenged a colleagues' laptop which was able to do it - so that gets us over this roadblock for now but isn't a sustainable solution.