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.

[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