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"