Uploaded image for project: 'Mender'
  1. Mender
  2. MEN-4829

Mender client looping non-stop when only user Control Map is active

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Done
    • Priority: (None)
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 3.0.0, 3.0.0-report
    • Labels:
    • Sprint:
      MEN Sprint 140
    • Backlog:
      yes
    • Days in progress:
      0

      Description

      When in mender-update-control -> mender-update-control-pause transition, the client only checks for update control maps with the particular UUID of the deployment in progress to decide if (and how long) to sleep. When only D-Bus side maps are present, the client will transition non-stop between mender-update-control -> mender-update-control-pause.

      It eventually "works", but:

      • It is busy waiting, therefore wasting CPU for potentially long time
      • The resulting log is enormous, making it very difficult to read for humans
      • The logs messages are rather confusing: one part of the log says "no control maps present" (this refers to no control maps for this particular Update ongoing), while other part of the log indicates that we need to pause due to a control map (this one refers to a control map set by the user via D-Bus).

      Extract of the log follows:

      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=info msg="State transition: mender-update-control [none] -> mender-update-control-pause [none]" func=github.com/mendersoftware/mender/app.transitionState file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/mender.go:510"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Handle controlMapPause state" func="github.com/mendersoftware/mender/app.(*controlMapPauseState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:2062"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=error msg="No control maps no longer present, continuing" func="github.com/mendersoftware/mender/app.(*controlMapPauseState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:2070"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=info msg="State transition: mender-update-control-pause [none] -> mender-update-control [none]" func=github.com/mendersoftware/mender/app.transitionState file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/mender.go:510"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Handling update control state" func="github.com/mendersoftware/mender/app.(*controlMapState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:1928"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Querying Update Control maps. Currently active maps: '[ID: 3702f9f0-b318-11eb-a7b6-c7aece07181e Priority: 0\nStates: map[ArtifactInstall_Enter:{pause continue pause}]]'" func="github.com/mendersoftware/mender/app.(*ControlMapPool).QueryAndUpdate" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/updatemanager.go:406"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Returning action \"pause\"" func="github.com/mendersoftware/mender/app.(*ControlMapPool).QueryAndUpdate" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/updatemanager.go:432"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Saving Update Control Maps to disk: \"{\\\"active\\\":[{\\\"id\\\":\\\"3702f9f0-b318-11eb-a7b6-c7aece07181e\\\",\\\"priority\\\":0,\\\"states\\\":{\\\"ArtifactInstall_Enter\\\":{\\\"action\\\":\\\"pause\\\",\\\"on_map_expire\\\":\\\"continue\\\",\\\"on_action_executed\\\":\\\"pause\\\"}}}],\\\"expired\\\":null}\"" func="github.com/mendersoftware/mender/app.(*ControlMapPool).saveToStore" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/updatemanager.go:332"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="controlMapState action: pause" func="github.com/mendersoftware/mender/app.(*controlMapState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:1931"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=info msg="Update Control: Pausing before entering update-install state" func="github.com/mendersoftware/mender/app.(*controlMapState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:1936"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Reporting update status: pause_before_installing" func="github.com/mendersoftware/mender/app.(*controlMapState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:1937"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=info msg="State transition: mender-update-control [none] -> mender-update-control-pause [none]" func=github.com/mendersoftware/mender/app.transitionState file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/mender.go:510"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Handle controlMapPause state" func="github.com/mendersoftware/mender/app.(*controlMapPauseState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:2062"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=error msg="No control maps no longer present, continuing" func="github.com/mendersoftware/mender/app.(*controlMapPauseState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:2070"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=info msg="State transition: mender-update-control-pause [none] -> mender-update-control [none]" func=github.com/mendersoftware/mender/app.transitionState file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/mender.go:510"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Handling update control state" func="github.com/mendersoftware/mender/app.(*controlMapState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:1928"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Querying Update Control maps. Currently active maps: '[ID: 3702f9f0-b318-11eb-a7b6-c7aece07181e Priority: 0\nStates: map[ArtifactInstall_Enter:{pause continue pause}]]'" func="github.com/mendersoftware/mender/app.(*ControlMapPool).QueryAndUpdate" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/updatemanager.go:406"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Returning action \"pause\"" func="github.com/mendersoftware/mender/app.(*ControlMapPool).QueryAndUpdate" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/updatemanager.go:432"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Saving Update Control Maps to disk: \"{\\\"active\\\":[{\\\"id\\\":\\\"3702f9f0-b318-11eb-a7b6-c7aece07181e\\\",\\\"priority\\\":0,\\\"states\\\":{\\\"ArtifactInstall_Enter\\\":{\\\"action\\\":\\\"pause\\\",\\\"on_map_expire\\\":\\\"continue\\\",\\\"on_action_executed\\\":\\\"pause\\\"}}}],\\\"expired\\\":null}\"" func="github.com/mendersoftware/mender/app.(*ControlMapPool).saveToStore" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/updatemanager.go:332"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="controlMapState action: pause" func="github.com/mendersoftware/mender/app.(*controlMapState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:1931"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=info msg="Update Control: Pausing before entering update-install state" func="github.com/mendersoftware/mender/app.(*controlMapState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:1936"
      Jul 02 13:58:03 vexpress-qemu mender[4390]: time="2021-07-02T13:58:03Z" level=debug msg="Reporting update status: pause_before_installing" func="github.com/mendersoftware/mender/app.(*controlMapState).Handle" file="/poky-build/crops-dunfell-vexpress-qemu/tmp/work/armv5-poky-linux-gnueabi/mender-client/master-gitAUTOINC+30412c6d59-r0/build/src/github.com/mendersoftware/mender/app/state.go:1937"
      

        Attachments

          Activity

            People

            Assignee:
            lluis Lluís Campos
            Reporter:
            lluis Lluís Campos
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:

                Zendesk Support