Reboot task during BOOTSTRAP provision

olebowle · February 18, 2022, 11:53am

Hi,

we occasionally have issues with provisioning CPEs coming from “0 BOOTSTRAP” while still having a left-over enqueued reboot task. It seems both the task and BOOTSTRAP provision (via the corresponding preset) are fired at the same time, leading to an unsuccessful provision due to the parallel reboot.

2022-01-17T08:49:58.475Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: Inform; cpeRequestId="100" informEvent="4 VALUE CHANGE,1 BOOT,0 BOOTSTRAP" informRetryCount=0
2022-01-17T08:49:58.503Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90000" acsRequestName="Reboot"
2022-01-17T08:49:58.540Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90200" acsRequestName="GetParameterNames"
2022-01-17T08:49:58.605Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90201" acsRequestName="GetParameterNames"
2022-01-17T08:49:58.671Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90202" acsRequestName="GetParameterNames"
2022-01-17T08:49:59.191Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90203" acsRequestName="GetParameterNames"
2022-01-17T08:49:59.664Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90204" acsRequestName="GetParameterNames"
2022-01-17T08:49:59.683Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90205" acsRequestName="GetParameterNames"
2022-01-17T08:49:59.740Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90206" acsRequestName="GetParameterNames"
2022-01-17T08:49:59.815Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90207" acsRequestName="GetParameterValues"
2022-01-17T08:49:59.885Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90208" acsRequestName="GetParameterNames"
2022-01-17T08:49:59.922Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90209" acsRequestName="GetParameterNames"
2022-01-17T08:49:59.981Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b9020a" acsRequestName="GetParameterNames"
2022-01-17T08:49:59.995Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b9020b" acsRequestName="GetParameterValues"
2022-01-17T08:50:00.010Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b9020c" acsRequestName="GetParameterNames"
2022-01-17T08:50:00.095Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b9020d" acsRequestName="GetParameterValues"
2022-01-17T08:50:00.174Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b9020e" acsRequestName="GetParameterNames"
2022-01-17T08:50:00.499Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b9020f" acsRequestName="GetParameterValues"
2022-01-17T08:50:00.527Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: ACS request; acsRequestId="17e673a90b90210" acsRequestName="SetParameterValues"
2022-01-17T08:50:28.932Z [ERROR] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: Bad session state
2022-01-17T08:52:29.277Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D55B7F09: Inform; cpeRequestId="100" informEvent="4 VALUE CHANGE,1 BOOT,M Reboot" informRetryCount=0

How can this be avoided / worked around? Some ideas from my side:

Can provisions/presets be prioritized over tasks? Can tasks be of a lower priority compared to a provision/preset?
Is it possible to delete tasks within a provision? We already do the following for every BOOTSTRAP provision:

clear('Device', Date.now());
clear('InternetGatewayDevice', Date.now());

Deleting a task here might be too late though, since I think the task and provision are fired at the same time.

Can reboot tasks generally be ignored for BOOTSTRAP provisions/presets?

What are your thoughts?

akcoder · February 18, 2022, 10:30pm

Which version of GenieACS are you using? IIRC, a BOOTSTRAP should cause all queued tasks to be removed.

olebowle · February 19, 2022, 11:12am

I’m on v1.2.8. It is still doing it. I just double checked:

$ rpm -q genieacs
genieacs-1.2.8-1.x86_64


$ curl -i 'http://localhost:7557/devices/00040E-FRITZ%2521Box-E0286D191E9A/tasks?connection_request' -X POST  --data '{ "name": "factoryReset" }'
HTTP/1.1 200 OK
GenieACS-Version: 1.2.8+20211027200938
Content-Type: application/json
Date: Sat, 19 Feb 2022 11:03:59 GMT
Connection: keep-alive
Keep-Alive: timeout=5
Transfer-Encoding: chunked

{"name":"factoryReset","device":"00040E-FRITZ%21Box-E0286D191E9A","timestamp":"2022-02-19T11:03:58.112Z","_id":"6210ce9e8a435f1dd10b2c6b"}


$ curl -i 'http://localhost:7557/devices/00040E-FRITZ%2521Box-E0286D191E9A/tasks' -X POST  --data '{ "name": "reboot" }'
HTTP/1.1 202 Accepted
GenieACS-Version: 1.2.8+20211027200938
Content-Type: application/json
Date: Sat, 19 Feb 2022 11:04:20 GMT
Connection: keep-alive
Keep-Alive: timeout=5
Transfer-Encoding: chunked

{"name":"reboot","device":"00040E-FRITZ%21Box-E0286D191E9A","timestamp":"2022-02-19T11:04:20.375Z","_id":"6210ceb406374f2124f2db01"}


$ curl -i 'http://localhost:7557/tasks' -X GET
HTTP/1.1 200 OK
GenieACS-Version: 1.2.8+20211027200938
Content-Type: application/json
total: 1
Date: Sat, 19 Feb 2022 11:05:07 GMT
Connection: keep-alive
Keep-Alive: timeout=5
Transfer-Encoding: chunked

[
{"_id":"6210ceb406374f2124f2db01","name":"reboot","device":"00040E-FRITZ%21Box-E0286D191E9A","timestamp":"2022-02-19T11:04:20.375Z"}
]

The log looks like this:

2022-02-19T11:03:58.374Z [INFO] ::ffff:127.0.0.1 00040E-FRITZ%21Box-E0286D191E9A: Inform; cpeRequestId="123" informEvent="6 CONNECTION REQUEST" informRetryCount=0
2022-02-19T11:03:58.430Z [INFO] ::ffff:127.0.0.1 00040E-FRITZ%21Box-E0286D191E9A: ACS request; acsRequestId="17f11a71a8b0100" acsRequestName="FactoryReset"
2022-02-19T11:03:58.719Z [INFO] ::ffff:127.0.0.1 00040E-FRITZ%21Box-E0286D191E9A: ACS request; acsRequestId="17f11a71a8b0300" acsRequestName="GetParameterNames"
2022-02-19T11:03:58.735Z [INFO] ::ffff:127.0.0.1 00040E-FRITZ%21Box-E0286D191E9A: ACS request; acsRequestId="17f11a71a8b0301" acsRequestName="GetParameterValues"
2022-02-19T11:07:54.956Z [INFO] ::ffff:127.0.0.1 00040E-FRITZ%21Box-E0286D191E9A: Inform; cpeRequestId="100" informEvent="4 VALUE CHANGE,1 BOOT,0 BOOTSTRAP" informRetryCount=0
2022-02-19T11:07:55.012Z [INFO] ::ffff:127.0.0.1 00040E-FRITZ%21Box-E0286D191E9A: ACS request; acsRequestId="17f11aab6a60000" acsRequestName="Reboot"
2022-02-19T11:07:55.081Z [INFO] ::ffff:127.0.0.1 00040E-FRITZ%21Box-E0286D191E9A: ACS request; acsRequestId="17f11aab6a60200" acsRequestName="GetParameterNames"
2022-02-19T11:08:26.102Z [ERROR] ::ffff:127.0.0.1 00040E-FRITZ%21Box-E0286D191E9A: Session timeout; sessionTimestamp=1645268874918
2022-02-19T11:08:26.103Z [WARN] ::ffff:127.0.0.1 00040E-FRITZ%21Box-E0286D191E9A: Channel has faulted; channel="default" retries=0 faultCode="session_terminated" faultMessage="The TR-069 session was unsuccessfully terminated"

mtarifa · February 28, 2022, 1:18pm

may be you need to add “-6 CONNECTION REQUEST” on default preset or any that will trigger in that condition like refresh_vparams. i had similar issue on a “reboot” command during boostrap provision.

Topic		Replies	Views
Events trigger order	10	1032	December 1, 2023
Share: bash scripts to solve boot events	0	264	August 15, 2023
Preset does not work well	10	1581	September 18, 2020
Seeing session timeout in GeniACS logs with two BOOTSTRAP	3	286	November 17, 2023
Provisionings executing twice	9	114	July 26, 2024

Reboot task during BOOTSTRAP provision

Related topics