SOLVED 3.2.0-beta4 pkg install fail



  • Hi *,

    I got asked to install 3.2.0-beta4-1. So I changed my pi from "stable" to "unstable", "apt update" and "apt upgrade":

    root@Blimy:/etc/apt/sources.list.d# apt upgrade
    Reading package lists... Done
    Building dependency tree       
    Reading state information... Done
    Calculating upgrade... Done
    The following packages will be upgraded:
      duetcontrolserver duetruntime duetsd duetsoftwareframework duettools duetwebcontrol duetwebserver reprapfirmware
    8 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
    Need to get 33.7 MB of archives.
    After this operation, 0 B of additional disk space will be used.
    Do you want to continue? [Y/n] 
    Get:1 https://pkg.duet3d.com unstable/armv7 armhf duetsoftwareframework armhf 3.2.0-beta4 [2,038 B]
    Get:2 https://pkg.duet3d.com unstable/armv7 armhf duetsd all 1.1.0 [2,102 B]
    Get:3 https://pkg.duet3d.com unstable/armv7 armhf duettools armhf 3.2.0-beta4 [62.4 kB]
    Get:4 https://pkg.duet3d.com unstable/armv7 armhf duetcontrolserver armhf 3.2.0-beta4 [228 kB]
    Get:5 https://pkg.duet3d.com unstable/armv7 armhf duetruntime armhf 3.2.0-beta4 [28.8 MB]
    Get:6 https://pkg.duet3d.com unstable/armv7 armhf duetwebserver armhf 3.2.0-beta4 [84.1 kB]                                                                 
    Get:7 https://pkg.duet3d.com unstable/armv7 armhf duetwebcontrol all 3.2.0-beta4 [3,507 kB]                                                                 
    Get:8 https://pkg.duet3d.com unstable/armv7 armhf reprapfirmware all 3.2.0-beta4-1 [989 kB]                                                                 
    Fetched 33.7 MB in 9s (3,947 kB/s)                                                                                                                          
    Reading changelogs... Done
    (Reading database ... 79828 files and directories currently installed.)
    Preparing to unpack .../0-duetsoftwareframework_3.2.0-beta4_armhf.deb ...
    Unpacking duetsoftwareframework (3.2.0-beta4) over (3.1.1) ...
    Preparing to unpack .../1-duetsd_1.1.0_all.deb ...
    Unpacking duetsd (1.1.0) over (1.0.6) ...
    Preparing to unpack .../2-duettools_3.2.0-beta4_armhf.deb ...
    Unpacking duettools (3.2.0-beta4) over (3.1.1) ...
    Preparing to unpack .../3-duetcontrolserver_3.2.0-beta4_armhf.deb ...
    Unpacking duetcontrolserver (3.2.0-beta4) over (3.1.1) ...
    Preparing to unpack .../4-duetruntime_3.2.0-beta4_armhf.deb ...
    Unpacking duetruntime (3.2.0-beta4) over (3.1.1) ...
    Preparing to unpack .../5-duetwebserver_3.2.0-beta4_armhf.deb ...
    Unpacking duetwebserver (3.2.0-beta4) over (3.1.0) ...
    Preparing to unpack .../6-duetwebcontrol_3.2.0-beta4_all.deb ...
    Unpacking duetwebcontrol (3.2.0-beta4) over (3.1.1) ...
    Preparing to unpack .../7-reprapfirmware_3.2.0-beta4-1_all.deb ...
    Unpacking reprapfirmware (3.2.0-beta4-1) over (3.1.1-1) ...
    Setting up duetruntime (3.2.0-beta4) ...
    Setting up duetcontrolserver (3.2.0-beta4) ...
    Installing new version of config file /opt/dsf/conf/config.json ...
    Creating group dsf with gid 995.
    Creating user dsf (n/a) with uid 995 and gid 995.
    Setting up duettools (3.2.0-beta4) ...
    Setting up duetwebserver (3.2.0-beta4) ...
    Setting up duetsoftwareframework (3.2.0-beta4) ...
    To modify config files consider adding yourself to the dsf groupd: # usermod -a -G dsf <username>
    Setting up duetwebcontrol (3.2.0-beta4) ...
    Setting up duetsd (1.1.0) ...
    Setting up reprapfirmware (3.2.0-beta4-1) ...
    Sending update request to DCS... Error: Failed to send update request
    Unhandled exception. System.Threading.Tasks.TaskCanceledException: A task was canceled.
       at DuetAPIClient.BaseConnection.PerformCommand[T](BaseCommand command, CancellationToken cancellationToken) in /home/christian/Duet3D/DuetSoftwareFramewor
    k/src/DuetAPIClient/BaseConnection.cs:line 188
       at DuetControlServer.Program.CheckForAnotherInstance() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/Program.cs:line 306
       at DuetControlServer.Program.Main(String[] args) in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/Program.cs:line 84
       at DuetControlServer.Program.<Main>(String[] args)
    Aborted
    root@Blimy:/etc/apt/sources.list.d# 
    

    It seems to me that there are some hardcoded leftovers. 😉

    So I executed the update "/opt/dsf/bin/DuetControlServer -u" which I found in "/var/lib/dpkg/info/reprapfirmware.postinst

    So it looks like it is OK now:

    Board: Duet 3 MB6HC (MB6HC)
    DSF Version: 3.2.0-beta4
    Firmware: RepRapFirmware for Duet 3 MB6HC 3.2-beta4 (2020-11-26)
    

    And the package install status seams to be OK too:

    root@Blimy:/var/lib/dpkg/info# apt upgrade
    Reading package lists... Done
    Building dependency tree       
    Reading state information... Done
    Calculating upgrade... Done
    0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
    
    ii  duetcontrolserver                    3.2.0-beta4                         armhf        Control server application for Duet 3 series
    ii  duetruntime                          3.2.0-beta4                         armhf        .NET Core runtime libraries for the Duet software framework
    ii  duetsd                               1.1.0                               all          Virtual SD card directory for the Duet software framework
    ii  duetsoftwareframework                3.2.0-beta4                         armhf        Meta package for the full Duet software framework
    ii  duettools                            3.2.0-beta4                         armhf        Optional tools (code examples)
    ii  duetwebcontrol                       3.2.0-beta4                         all          Official web interface for Duet electronics
    ii  duetwebserver                        3.2.0-beta4                         armhf        Optional web server for Duet 3 series
    

    So it seems to me that my setup is clean now, but it seems not "end user friendly".

    Cheers, Chriss


  • administrators

    It is quite odd that DCS cancelled the update request, that could only occur if it receives SIGTERM before the update request is processed. Can you please check the log via journalctl -u duetcontrolserver and share the section where the first update attempt is performed?



  • @chrishamm

    I'm not sure that I can be helpful here. I'm not able to identify any strange things here, but my filter on my "/dev/input/eyes" not traind for DCS logs. 😉 So here is the full dump. The timezone of the pi is "GMT"

    -- Logs begin at Tue 2020-12-01 17:17:01 GMT, end at Tue 2020-12-01 18:50:33 GMT. --
    Dec 01 17:17:04 Blimy systemd[1]: Started Duet Control Server.
    Dec 01 17:17:08 Blimy DuetControlServer[392]: Duet Control Server v3.2.0-beta4
    Dec 01 17:17:08 Blimy DuetControlServer[392]: Written by Christian Hammacher for Duet3D
    Dec 01 17:17:08 Blimy DuetControlServer[392]: Licensed under the terms of the GNU Public License Version 3
    Dec 01 17:17:10 Blimy DuetControlServer[392]: [info] Settings loaded
    Dec 01 17:17:10 Blimy DuetControlServer[392]: [info] Environment initialized
    Dec 01 17:17:10 Blimy DuetControlServer[392]: [info] Connection to Duet established
    Dec 01 17:17:10 Blimy DuetControlServer[392]: [info] IPC socket created at /var/run/dsf/dcs.sock
    Dec 01 17:17:11 Blimy DuetControlServer[392]: [info] Starting macro file config.g on channel Trigger
    Dec 01 17:17:12 Blimy DuetControlServer[392]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 1
    Dec 01 17:17:13 Blimy DuetControlServer[392]: [error] M584: Response timeout: CAN addr 1, req type 6042, RID=1
    Dec 01 17:17:13 Blimy DuetControlServer[392]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 2
    Dec 01 17:17:14 Blimy DuetControlServer[392]: [error] M350: Response timeout: CAN addr 1, req type 6042, RID=2
    Dec 01 17:17:14 Blimy DuetControlServer[392]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 3
    Dec 01 17:17:15 Blimy DuetControlServer[392]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 4
    Dec 01 17:17:15 Blimy DuetControlServer[392]: [error] M92: Response timeout: CAN addr 1, req type 6042, RID=3
    Dec 01 17:17:16 Blimy DuetControlServer[392]: [error] M906: Response timeout: CAN addr 1, req type 6043, RID=4
    Dec 01 17:17:16 Blimy DuetControlServer[392]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 5
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [warn] Lost connection to Duet (Timeout while waiting for transfer ready pin)
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [info] Connection to Duet established
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [error] M591: Response timeout: CAN addr 1, req type 6046, RID=5
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [info] Starting macro file config-override.g on channel Trigger
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [info] Finished macro file config-override.g
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [warn] M307: Heater 0 appears to be over-powered. If left on at full power, its temperature is predicted to
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [warn] M307: Heater 1 appears to be over-powered. If left on at full power, its temperature is predicted to
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [info] Finished macro file config.g
    Dec 01 17:43:29 Blimy DuetControlServer[392]: [info] System time has been changed
    Dec 01 17:43:30 Blimy DuetControlServer[392]: [info] Starting macro file 0:/macros/20_Z-Level on channel HTTP
    Dec 01 17:43:30 Blimy DuetControlServer[392]: [info] Starting macro file bed.g on channel HTTP
    Dec 01 17:43:30 Blimy DuetControlServer[392]: [info] Starting macro file homeall.g on channel HTTP
    Dec 01 17:43:30 Blimy DuetControlServer[392]: [info] Starting macro file 0:/sys/homex.g on channel HTTP
    Dec 01 17:43:53 Blimy DuetControlServer[392]: [info] Finished macro file 0:/sys/homex.g
    Dec 01 17:43:53 Blimy DuetControlServer[392]: [info] Starting macro file 0:/sys/homey.g on channel HTTP
    Dec 01 17:44:01 Blimy DuetControlServer[392]: [info] Finished macro file 0:/sys/homey.g
    Dec 01 17:44:01 Blimy DuetControlServer[392]: [info] Starting macro file 0:/sys/homez.g on channel HTTP
    Dec 01 17:44:02 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel HTTP
    Dec 01 17:44:03 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:44:05 Blimy DuetControlServer[392]: [info] Starting macro file retractprobe.g on channel HTTP
    Dec 01 17:44:05 Blimy DuetControlServer[392]: [info] Finished macro file retractprobe.g
    Dec 01 17:44:07 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel HTTP
    Dec 01 17:44:07 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:44:12 Blimy DuetControlServer[392]: [info] Starting macro file retractprobe.g on channel HTTP
    Dec 01 17:44:12 Blimy DuetControlServer[392]: [info] Finished macro file retractprobe.g
    Dec 01 17:44:13 Blimy DuetControlServer[392]: [info] Finished macro file 0:/sys/homez.g
    Dec 01 17:44:13 Blimy DuetControlServer[392]: [info] Finished macro file homeall.g
    Dec 01 17:44:16 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel HTTP
    Dec 01 17:44:16 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:44:16 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    -- Logs begin at Tue 2020-12-01 17:17:01 GMT, end at Tue 2020-12-01 18:50:33 GMT. --
    Dec 01 17:17:04 Blimy systemd[1]: Started Duet Control Server.
    Dec 01 17:17:08 Blimy DuetControlServer[392]: Duet Control Server v3.2.0-beta4
    Dec 01 17:17:08 Blimy DuetControlServer[392]: Written by Christian Hammacher for Duet3D
    Dec 01 17:17:08 Blimy DuetControlServer[392]: Licensed under the terms of the GNU Public License Version 3
    Dec 01 17:17:10 Blimy DuetControlServer[392]: [info] Settings loaded
    Dec 01 17:17:10 Blimy DuetControlServer[392]: [info] Environment initialized
    Dec 01 17:17:10 Blimy DuetControlServer[392]: [info] Connection to Duet established
    Dec 01 17:17:10 Blimy DuetControlServer[392]: [info] IPC socket created at /var/run/dsf/dcs.sock
    Dec 01 17:17:11 Blimy DuetControlServer[392]: [info] Starting macro file config.g on channel Trigger
    Dec 01 17:17:12 Blimy DuetControlServer[392]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 1
    Dec 01 17:17:13 Blimy DuetControlServer[392]: [error] M584: Response timeout: CAN addr 1, req type 6042, RID=1
    Dec 01 17:17:13 Blimy DuetControlServer[392]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 2
    Dec 01 17:17:14 Blimy DuetControlServer[392]: [error] M350: Response timeout: CAN addr 1, req type 6042, RID=2
    Dec 01 17:17:14 Blimy DuetControlServer[392]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 3
    Dec 01 17:17:15 Blimy DuetControlServer[392]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 4
    Dec 01 17:17:15 Blimy DuetControlServer[392]: [error] M92: Response timeout: CAN addr 1, req type 6042, RID=3
    Dec 01 17:17:16 Blimy DuetControlServer[392]: [error] M906: Response timeout: CAN addr 1, req type 6043, RID=4
    Dec 01 17:17:16 Blimy DuetControlServer[392]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 5
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [warn] Lost connection to Duet (Timeout while waiting for transfer ready pin)
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [info] Connection to Duet established
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [error] M591: Response timeout: CAN addr 1, req type 6046, RID=5
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [info] Starting macro file config-override.g on channel Trigger
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [info] Finished macro file config-override.g
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [warn] M307: Heater 0 appears to be over-powered. If left on at full power, its temperature is predicted to
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [warn] M307: Heater 1 appears to be over-powered. If left on at full power, its temperature is predicted to
    Dec 01 17:17:17 Blimy DuetControlServer[392]: [info] Finished macro file config.g
    Dec 01 17:43:29 Blimy DuetControlServer[392]: [info] System time has been changed
    Dec 01 17:43:30 Blimy DuetControlServer[392]: [info] Starting macro file 0:/macros/20_Z-Level on channel HTTP
    Dec 01 17:43:30 Blimy DuetControlServer[392]: [info] Starting macro file bed.g on channel HTTP
    Dec 01 17:43:30 Blimy DuetControlServer[392]: [info] Starting macro file homeall.g on channel HTTP
    Dec 01 17:43:30 Blimy DuetControlServer[392]: [info] Starting macro file 0:/sys/homex.g on channel HTTP
    Dec 01 17:43:53 Blimy DuetControlServer[392]: [info] Finished macro file 0:/sys/homex.g
    Dec 01 17:43:53 Blimy DuetControlServer[392]: [info] Starting macro file 0:/sys/homey.g on channel HTTP
    Dec 01 17:44:01 Blimy DuetControlServer[392]: [info] Finished macro file 0:/sys/homey.g
    Dec 01 17:44:01 Blimy DuetControlServer[392]: [info] Starting macro file 0:/sys/homez.g on channel HTTP
    Dec 01 17:44:02 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel HTTP
    Dec 01 17:44:03 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:44:05 Blimy DuetControlServer[392]: [info] Starting macro file retractprobe.g on channel HTTP
    Dec 01 17:44:05 Blimy DuetControlServer[392]: [info] Finished macro file retractprobe.g
    Dec 01 17:44:07 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel HTTP
    Dec 01 17:44:07 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:44:12 Blimy DuetControlServer[392]: [info] Starting macro file retractprobe.g on channel HTTP
    Dec 01 17:44:12 Blimy DuetControlServer[392]: [info] Finished macro file retractprobe.g
    Dec 01 17:44:13 Blimy DuetControlServer[392]: [info] Finished macro file 0:/sys/homez.g
    Dec 01 17:44:13 Blimy DuetControlServer[392]: [info] Finished macro file homeall.g
    Dec 01 17:44:16 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel HTTP
    Dec 01 17:44:16 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:44:16 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel HTTP
    Dec 01 17:44:16 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:44:17 Blimy DuetControlServer[392]: [info] Starting macro file retractprobe.g on channel HTTP
    Dec 01 17:44:17 Blimy DuetControlServer[392]: [info] Finished macro file retractprobe.g
    Dec 01 17:44:22 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel HTTP
    Dec 01 17:44:23 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:44:24 Blimy DuetControlServer[392]: [info] Starting macro file retractprobe.g on channel HTTP
    Dec 01 17:44:24 Blimy DuetControlServer[392]: [info] Finished macro file retractprobe.g
    Dec 01 17:44:29 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel HTTP
    Dec 01 17:44:29 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:44:30 Blimy DuetControlServer[392]: [info] Starting macro file retractprobe.g on channel HTTP
    Dec 01 17:44:30 Blimy DuetControlServer[392]: [info] Finished macro file retractprobe.g
    Dec 01 17:44:32 Blimy DuetControlServer[392]: [info] Finished macro file bed.g
    Dec 01 17:44:32 Blimy DuetControlServer[392]: [info] Finished macro file 0:/macros/20_Z-Level
    Dec 01 17:44:49 Blimy DuetControlServer[392]: [info] Selected file /opt/dsf/sd/gcodes/CFFFP_Stringing.gcode
    Dec 01 17:44:49 Blimy DuetControlServer[392]: [info] Starting file print
    Dec 01 17:44:49 Blimy DuetControlServer[392]: [info] Starting macro file tpre0.g on channel File
    Dec 01 17:44:49 Blimy DuetControlServer[392]: [info] Finished macro file tpre0.g
    Dec 01 17:44:49 Blimy DuetControlServer[392]: [info] Starting macro file tpost0.g on channel File
    Dec 01 17:44:49 Blimy DuetControlServer[392]: [info] Finished macro file tpost0.g
    Dec 01 17:45:55 Blimy DuetControlServer[392]: [info] Starting macro file homeall.g on channel File
    Dec 01 17:45:55 Blimy DuetControlServer[392]: [info] Starting macro file 0:/sys/homex.g on channel File
    Dec 01 17:46:14 Blimy DuetControlServer[392]: [info] Finished macro file 0:/sys/homex.g
    Dec 01 17:46:14 Blimy DuetControlServer[392]: [info] Starting macro file 0:/sys/homey.g on channel File
    Dec 01 17:46:22 Blimy DuetControlServer[392]: [info] Finished macro file 0:/sys/homey.g
    Dec 01 17:46:22 Blimy DuetControlServer[392]: [info] Starting macro file 0:/sys/homez.g on channel File
    Dec 01 17:46:24 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel File
    Dec 01 17:46:24 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:46:25 Blimy DuetControlServer[392]: [info] Starting macro file retractprobe.g on channel File
    Dec 01 17:46:25 Blimy DuetControlServer[392]: [info] Finished macro file retractprobe.g
    Dec 01 17:46:27 Blimy DuetControlServer[392]: [info] Starting macro file deployprobe.g on channel File
    Dec 01 17:46:27 Blimy DuetControlServer[392]: [info] Finished macro file deployprobe.g
    Dec 01 17:46:32 Blimy DuetControlServer[392]: [info] Starting macro file retractprobe.g on channel File
    Dec 01 17:46:32 Blimy DuetControlServer[392]: [info] Finished macro file retractprobe.g
    Dec 01 17:46:33 Blimy DuetControlServer[392]: [info] Finished macro file 0:/sys/homez.g
    Dec 01 17:46:33 Blimy DuetControlServer[392]: [info] Finished macro file homeall.g
    Dec 01 17:46:34 Blimy DuetControlServer[392]: [info] Height map loaded from file heightmap.csv
    Dec 01 17:47:48 Blimy DuetControlServer[392]: [info] Starting macro file pause.g on channel HTTP
    Dec 01 17:47:48 Blimy DuetControlServer[392]: [info] Job has been paused at byte 5145, reason User
    Dec 01 17:47:50 Blimy DuetControlServer[392]: [info] Finished macro file pause.g
    Dec 01 17:54:17 Blimy DuetControlServer[392]: [info] Starting macro file tfree0.g on channel HTTP
    Dec 01 17:54:17 Blimy DuetControlServer[392]: [info] Finished macro file tfree0.g
    Dec 01 18:01:02 Blimy DuetControlServer[392]: [info] Aborted job file
    Dec 01 18:01:03 Blimy DuetControlServer[392]: [warn] Emergency stop
    Dec 01 18:01:03 Blimy DuetControlServer[392]: [warn] Resetting controller
    Dec 01 18:01:03 Blimy DuetControlServer[392]: [info] Application has shut down
    Dec 01 18:01:03 Blimy systemd[1]: duetcontrolserver.service: Succeeded.
    Dec 01 18:01:08 Blimy systemd[1]: duetcontrolserver.service: Service RestartSec=5s expired, scheduling restart.
    Dec 01 18:01:08 Blimy systemd[1]: duetcontrolserver.service: Scheduled restart job, restart counter is at 1.
    Dec 01 18:01:08 Blimy systemd[1]: Stopped Duet Control Server.
    Dec 01 18:01:08 Blimy systemd[1]: Started Duet Control Server.
    Dec 01 18:01:09 Blimy DuetControlServer[5172]: Duet Control Server v3.2.0-beta4
    Dec 01 18:01:09 Blimy DuetControlServer[5172]: Written by Christian Hammacher for Duet3D
    Dec 01 18:01:09 Blimy DuetControlServer[5172]: Licensed under the terms of the GNU Public License Version 3
    Dec 01 18:01:10 Blimy DuetControlServer[5172]: [info] Settings loaded
    Dec 01 18:01:10 Blimy DuetControlServer[5172]: [info] Environment initialized
    Dec 01 18:01:11 Blimy DuetControlServer[5172]: [info] Connection to Duet established
    Dec 01 18:01:11 Blimy DuetControlServer[5172]: [info] IPC socket created at /var/run/dsf/dcs.sock
    Dec 01 18:01:11 Blimy DuetControlServer[5172]: [info] Starting macro file config.g on channel Trigger
    Dec 01 18:01:13 Blimy DuetControlServer[5172]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 1
    Dec 01 18:01:14 Blimy DuetControlServer[5172]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 2
    Dec 01 18:01:14 Blimy DuetControlServer[5172]: [error] M584: Response timeout: CAN addr 1, req type 6042, RID=1
    Dec 01 18:01:15 Blimy DuetControlServer[5172]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 3
    Dec 01 18:01:15 Blimy DuetControlServer[5172]: [error] M350: Response timeout: CAN addr 1, req type 6042, RID=2
    Dec 01 18:01:16 Blimy DuetControlServer[5172]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 4
    Dec 01 18:01:16 Blimy DuetControlServer[5172]: [error] M92: Response timeout: CAN addr 1, req type 6042, RID=3
    Dec 01 18:01:17 Blimy DuetControlServer[5172]: [error] M906: Response timeout: CAN addr 1, req type 6043, RID=4
    Dec 01 18:01:17 Blimy DuetControlServer[5172]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 5
    Dec 01 18:01:18 Blimy DuetControlServer[5172]: [warn] Lost connection to Duet (Timeout while waiting for transfer ready pin)
    Dec 01 18:01:18 Blimy DuetControlServer[5172]: [info] Connection to Duet established
    Dec 01 18:01:18 Blimy DuetControlServer[5172]: [error] M591: Response timeout: CAN addr 1, req type 6046, RID=5
    Dec 01 18:01:18 Blimy DuetControlServer[5172]: [info] Starting macro file config-override.g on channel Trigger
    Dec 01 18:01:18 Blimy DuetControlServer[5172]: [info] Finished macro file config-override.g
    Dec 01 18:01:19 Blimy DuetControlServer[5172]: [warn] M307: Heater 0 appears to be over-powered. If left on at full power, its temperature is predicted t
    Dec 01 18:01:19 Blimy DuetControlServer[5172]: [warn] M307: Heater 1 appears to be over-powered. If left on at full power, its temperature is predicted t
    Dec 01 18:01:19 Blimy DuetControlServer[5172]: [info] Finished macro file config.g
    Dec 01 18:01:39 Blimy DuetControlServer[5172]: [info] Starting macro file tpre0.g on channel HTTP
    Dec 01 18:01:39 Blimy DuetControlServer[5172]: [info] Finished macro file tpre0.g
    Dec 01 18:01:39 Blimy DuetControlServer[5172]: [info] Starting macro file tpost0.g on channel HTTP
    Dec 01 18:02:49 Blimy DuetControlServer[5172]: [info] Finished macro file tpost0.g
    

    I have to mention again that systemd sucks. 😞

    I hope that helps somehow.

    Cheers, Chriss



  • @chrishamm said in 3.2.0-beta4 pkg install fail:

    journalctl -u duetcontrolserver

    I did the upgrade today again... other topic, but I have a exception now:

    Dec 02 07:57:22 Blimy systemd[1]: Started Duet Control Server.
    Dec 02 07:57:23 Blimy DuetControlServer[2416]: Duet Control Server v3.2.0-beta4
    Dec 02 07:57:23 Blimy DuetControlServer[2416]: Written by Christian Hammacher for Duet3D
    Dec 02 07:57:23 Blimy DuetControlServer[2416]: Licensed under the terms of the GNU Public License Version 3
    Dec 02 07:57:23 Blimy DuetControlServer[2416]: [info] Settings loaded
    Dec 02 07:57:24 Blimy DuetControlServer[2416]: [info] Environment initialized
    Dec 02 07:57:24 Blimy DuetControlServer[2416]: [warn] Downgrading protocol version 3 to 2
    Dec 02 07:57:24 Blimy DuetControlServer[2416]: [warn] Incompatible firmware, please upgrade as soon as possible
    Dec 02 07:57:24 Blimy DuetControlServer[2416]: [info] Connection to Duet established
    Dec 02 07:57:24 Blimy DuetControlServer[2416]: [info] IPC socket created at /var/run/dsf/dcs.sock
    Dec 02 07:57:25 Blimy DuetControlServer[2416]: [error] Failed to merge JSON: {"key":"spindles","flags":"d99vn","result":[{"active":0,"current":0,"frequency":0,"max"
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    System.Text.Json.JsonException: Failed to deserialize property [Spindle].Max (type Int32) from JSON 10000.0000000
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:  ---> System.Text.Json.JsonException: The JSON value could not be converted to System.Int32. Path: $ | LineNumber: 0 
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:  ---> System.FormatException: Either the JSON value is not in a supported format, or is out of bounds for an Int32.
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at System.Text.Json.Utf8JsonReader.GetInt32()
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at System.Text.Json.Serialization.Converters.JsonConverterInt32.Read(Utf8JsonReader& reader, Type typeToConvert, J
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at System.Text.Json.JsonPropertyInfoNotNullable`4.OnRead(ReadStack& state, Utf8JsonReader& reader)
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at System.Text.Json.JsonPropertyInfo.Read(JsonTokenType tokenType, ReadStack& state, Utf8JsonReader& reader)
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at System.Text.Json.JsonSerializer.ReadCore(JsonSerializerOptions options, Utf8JsonReader& reader, ReadStack& read
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    --- End of inner exception stack trace ---
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at System.Text.Json.ThrowHelper.ReThrowWithPath(ReadStack& readStack, Utf8JsonReader& reader, Exception ex)
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at System.Text.Json.JsonSerializer.ReadCore(JsonSerializerOptions options, Utf8JsonReader& reader, ReadStack& read
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at System.Text.Json.JsonSerializer.ReadCore(Type returnType, JsonSerializerOptions options, Utf8JsonReader& reader
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at System.Text.Json.JsonSerializer.Deserialize(String json, Type returnType, JsonSerializerOptions options)
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at DuetAPI.ObjectModel.ModelObject.UpdateFromJson(JsonElement jsonElement, Boolean ignoreSbcProperties) in /home/c
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    --- End of inner exception stack trace ---
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at DuetAPI.ObjectModel.ModelObject.UpdateFromJson(JsonElement jsonElement, Boolean ignoreSbcProperties) in /home/c
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at DuetAPI.ObjectModel.ModelCollectionHelper.UpdateFromJson(IList list, Type itemType, JsonElement jsonElement, Bo
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at DuetAPI.ObjectModel.ObjectModel.InternalUpdateFromModel(String key, JsonElement jsonElement, Boolean ignoreSbcP
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at DuetAPI.ObjectModel.ObjectModel.UpdateFromFirmwareModel(String key, JsonElement jsonElement) in /home/christian
    Dec 02 07:57:25 Blimy DuetControlServer[2416]:    at DuetControlServer.Model.Updater.Run() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/Mod
    Dec 02 07:57:31 Blimy DuetControlServer[2416]: [info] Flashing IAP binary
    Dec 02 07:57:31 Blimy DuetControlServer[2416]: [info] Flashing RepRapFirmware
    Dec 02 07:57:38 Blimy DuetControlServer[2416]: [info] Verifying checksum
    Dec 02 07:57:40 Blimy DuetControlServer[2416]: [info] Firmware update successful
    Dec 02 07:57:40 Blimy DuetControlServer[2416]: [warn] Upgrading protocol version 2 to 3
    Dec 02 07:57:40 Blimy DuetControlServer[2416]: [fatal] Abnormal program termination
    Dec 02 07:57:40 Blimy DuetControlServer[2416]: [fatal] SPI task faulted
    Dec 02 07:57:40 Blimy DuetControlServer[2416]:    System.Exception: RepRapFirmware refused protocol version
    Dec 02 07:57:40 Blimy DuetControlServer[2416]:    at DuetControlServer.SPI.DataTransfer.ExchangeHeader() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetCon
    Dec 02 07:57:40 Blimy DuetControlServer[2416]:    at DuetControlServer.SPI.DataTransfer.PerformFullTransfer(Boolean connecting) in /home/christian/Duet3D/DuetSoftwa
    Dec 02 07:57:40 Blimy DuetControlServer[2416]:    at DuetControlServer.SPI.Interface.Run() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/SPI
    Dec 02 07:57:41 Blimy DuetControlServer[2416]: [fatal] SPI task faulted
    Dec 02 07:57:41 Blimy DuetControlServer[2416]:    System.Exception: RepRapFirmware refused protocol version
    Dec 02 07:57:41 Blimy DuetControlServer[2416]:    at DuetControlServer.SPI.DataTransfer.ExchangeHeader() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetCon
    Dec 02 07:57:41 Blimy DuetControlServer[2416]:    at DuetControlServer.SPI.DataTransfer.PerformFullTransfer(Boolean connecting) in /home/christian/Duet3D/DuetSoftwa
    Dec 02 07:57:41 Blimy DuetControlServer[2416]:    at DuetControlServer.SPI.Interface.Run() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/SPI
    Dec 02 07:57:41 Blimy DuetControlServer[2416]: [info] Application has shut down
    Dec 02 07:57:41 Blimy systemd[1]: duetcontrolserver.service: Succeeded.
    Dec 02 07:57:46 Blimy systemd[1]: duetcontrolserver.service: Service RestartSec=5s expired, scheduling restart.
    Dec 02 07:57:46 Blimy systemd[1]: duetcontrolserver.service: Scheduled restart job, restart counter is at 1.
    Dec 02 07:57:46 Blimy systemd[1]: Stopped Duet Control Server.
    Dec 02 07:57:46 Blimy systemd[1]: Started Duet Control Server.
    Dec 02 07:57:46 Blimy DuetControlServer[2525]: Duet Control Server v3.2.0-beta4
    Dec 02 07:57:46 Blimy DuetControlServer[2525]: Written by Christian Hammacher for Duet3D
    Dec 02 07:57:46 Blimy DuetControlServer[2525]: Licensed under the terms of the GNU Public License Version 3
    Dec 02 07:57:47 Blimy DuetControlServer[2525]: [info] Settings loaded
    Dec 02 07:57:47 Blimy DuetControlServer[2525]: [info] Environment initialized
    Dec 02 07:57:47 Blimy DuetControlServer[2525]: [info] Connection to Duet established
    Dec 02 07:57:47 Blimy DuetControlServer[2525]: [info] IPC socket created at /var/run/dsf/dcs.sock
    Dec 02 07:57:47 Blimy DuetControlServer[2525]: [info] Starting macro file config.g on channel Trigger
    Dec 02 07:57:48 Blimy DuetControlServer[2525]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 1
    Dec 02 07:57:49 Blimy DuetControlServer[2525]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 2
    Dec 02 07:57:49 Blimy DuetControlServer[2525]: [error] M584: Response timeout: CAN addr 1, req type 6042, RID=1
    Dec 02 07:57:50 Blimy DuetControlServer[2525]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 3
    Dec 02 07:57:50 Blimy DuetControlServer[2525]: [error] M350: Response timeout: CAN addr 1, req type 6042, RID=2
    Dec 02 07:57:51 Blimy DuetControlServer[2525]: [error] M92: Response timeout: CAN addr 1, req type 6042, RID=3
    Dec 02 07:57:51 Blimy DuetControlServer[2525]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 4
    Dec 02 07:57:52 Blimy DuetControlServer[2525]: [error] M906: Response timeout: CAN addr 1, req type 6043, RID=4
    Dec 02 07:57:52 Blimy DuetControlServer[2525]: [warn] Lost connection to Duet (Timeout while waiting for transfer ready pin)
    Dec 02 07:57:53 Blimy DuetControlServer[2525]: [info] Connection to Duet established
    Dec 02 07:57:53 Blimy DuetControlServer[2525]: [warn] Discarded msg src=1 typ=4510 RID=4095 exp 5
    Dec 02 07:57:53 Blimy DuetControlServer[2525]: [error] M591: Response timeout: CAN addr 1, req type 6046, RID=5
    Dec 02 07:57:53 Blimy DuetControlServer[2525]: [info] Starting macro file config-override.g on channel Trigger
    Dec 02 07:57:53 Blimy DuetControlServer[2525]: [info] Finished macro file config-override.g
    Dec 02 07:57:53 Blimy DuetControlServer[2525]: [warn] M307: Heater 0 appears to be over-powered. If left on at full power, its temperature is predicted to reach 245
    Dec 02 07:57:53 Blimy DuetControlServer[2525]: [warn] M307: Heater 1 appears to be over-powered. If left on at full power, its temperature is predicted to reach 512
    Dec 02 07:57:53 Blimy DuetControlServer[2525]: [info] Finished macro file config.g
    
    

    And the FW seams to be on 3.2-beta4 now:

    02/12/2020, 09:00:44	M115 B0
    FIRMWARE_NAME: RepRapFirmware for Duet 3 MB6HC FIRMWARE_VERSION: 3.2-beta4 ELECTRONICS: Duet 3 MB6HC v0.6 or 1.0 FIRMWARE_DATE: 2020-11-26
    

    I hope that helps....

    Cheers, Chriss



  • And the FW upgrate of the expantion board do not work:

    M997 B1
    02/12/2020, 09:03:22	Error: Firmware file Duet3Firmware_EXP3HC.bin not found
    

    But the file is there and the checksum indicates that it is 3.2-beta4. I downloaded it and compared the checksum:

    root@Blimy:~/3.2-beta4# sha256sum /opt/dsf/sd/sys/Duet3Firmware_EXP3HC.bin
    644c9127d702975eb610d67126d060628083e3cc914e7dab3c7ddbec2abecc87  /opt/dsf/sd/sys/Duet3Firmware_EXP3HC.bin
    root@Blimy:~/3.2-beta4# sha256sum ~/3.2-beta4/Duet3Firmware_EXP3HC.bin 
    644c9127d702975eb610d67126d060628083e3cc914e7dab3c7ddbec2abecc87  /root/3.2-beta4/Duet3Firmware_EXP3HC.bin
    

    I'm confused.....

    Cheers, Chriss


  • administrators

    @Chriss Thanks for the logs, I'll have a look at them now.

    It's a known issue that RRF 3.2-b4 fails to update CAN expansion boards, please install the new experimental MB6HC firmware from dc42's Dropbox (upload it on the Files -> System page and confirm the update prompt). Then you should be able to update the expansion boards via M997 B1.

    We'll provide a new RRF build via the package feed soon.

    Edit: I've just found the reason for the last exception and I'll fix it in 3.2.0-b5.



  • @chrishamm said in 3.2.0-beta4 pkg install fail:

    02/12/2020, 13:22:26	M115 B1
    Duet EXP3HC firmware version 3.2-beta4 (2020-11-26)
    02/12/2020, 13:22:22	M115 B0
    FIRMWARE_NAME: RepRapFirmware for Duet 3 MB6HC FIRMWARE_VERSION: 3.2-beta4+4 ELECTRONICS: Duet 3 MB6HC v0.6 or 1.0 FIRMWARE_DATE: 2020-11-29
    

    That did the trick, thank you very much.... I think that @dc42 was not aware that I have the 3HC connected. I'm sure that he would have mentioned that problem before he let me run into that. 😉 (The request to upgrade came from him on my filament sensor problem thread.)

    Edit: I've just found the reason for the last exception and I'll fix it in 3.2.0-b5.

    👍 I hope that my logs where useful to find the bug. 😉 I have a ruff idea when I see the "Failed to merge JSON" exception. 😄

    Cheers, Chriss


  • administrators

    @Chriss The JSON exception is actually properly handled and it won't show up if you start DCS in update-only mode (with the -u parameter) but there was a bug in the SPI protocol upgrade when upgrading from an older firmware. That's where your logs helped me 👍


Log in to reply