FactoryReset Loop

olebowle · December 11, 2020, 8:45am

Hi,

I am currently trying to investigate a factory reset loop between at least AVM devices and GenieACS v1.1.3 and v1.2.3. In fact I just updated to v1.2.3 to see if this issues was fixed. But unfortunately it seems the problem still persists. I am trying to factory reset a device via CWMP and later provision it using a preset matching the serial number pointing to a provision, which reacts on the EVENT “0 BOOTSTRAP”.

PRESET:
{"_id":“prov-2”,“weight”:0,“precondition”:"DeviceID.SerialNumber = “3810D5697542"”,“events”:{“0 BOOTSTRAP”:true},“configurations”:[{“type”:“provision”,“name”:“prov-2”,“args”:null}]}

I initiated the factory reset using the API. The following task can be retrieved:
{"_id":“5fd11bb5c334895a945152b8”,“name”:“factoryReset”,“device”:“00040E-FRITZ%21Box-3810D5697542”,“timestamp”:“2020-12-09T18:47:17.430Z”}

On next Inform (I didn’t use connection_request) GenieACS correctly tries to factory reset the device. However, the task is never removed. Thus, on next Bootstrap Inform (since the device did a factory reset) it will be factory reset again. This leads to a factory reset loop of the device. In effect it will be never be provisioned and remains unusable unless I manually remove the task.

I upload a pcap file (https://apackets.com/pcaps?pcap=219f86032cf97227b8849c23f0c76c7f.pcap&view=charts) showing three factory resets. Looking closely at the first TCP session, one can see, that there is no FactoryResetRespone from the device. I can understand, that GenieACS won’t remove the task unless a FactoryResetRespone is received.

However, in the next two retries one can clearly see the response (packet number 23 and 81). You may want to filter for ‘xml.tag == “cwmp:FactoryResetResponse/”’. GenieACS furthermore is trying to get parameter names and values after the factory reset was initiated. This will of course time out at some point, since the devices is resetting. From my point of view GenieACS should only do the FactoryReset, without further commands.

Even if this fails (and maybe as a workaround), I would expect that GenieACS deletes all FactoryReset tasks if the device sends an Inform with event “0 BOOTSTRAP”.

Below you can find the Log during the three factory resets:

LOOP0

2020-12-09T18:50:05.881Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Inform; cpeRequestId=“100” informEvent=“4 VALUE CHANGE,1 BOOT,0 BOOTSTRAP” informRetryCount=0
2020-12-09T18:50:05.887Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d6cead0000” acsRequestName=“FactoryReset”
2020-12-09T18:50:35.890Z [ERROR] 127.0.0.1: Session timeout; sessionTimestamp=1607539805869 deviceId=“00040E-FRITZ%21Box-3810D5697542”

LOOP1

2020-12-09T18:52:56.135Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Inform; cpeRequestId=“100” informEvent=“4 VALUE CHANGE,1 BOOT,0 BOOTSTRAP” informRetryCount=0
2020-12-09T18:52:56.142Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00000” acsRequestName=“FactoryReset”
2020-12-09T18:52:56.382Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00200” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.403Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00201” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.430Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00202” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.468Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00203” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.488Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00204” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.496Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00205” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.547Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00206” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.555Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00207” acsRequestName=“GetParameterValues”
2020-12-09T18:52:56.609Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00208” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.661Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00209” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.713Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c0020a” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.721Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c0020b” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.735Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c0020c” acsRequestName=“GetParameterValues”
2020-12-09T18:52:56.786Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c0020d” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.801Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c0020e” acsRequestName=“GetParameterNames”
2020-12-09T18:52:56.851Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c0020f” acsRequestName=“GetParameterValues”
2020-12-09T18:52:56.915Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648d967c00210” acsRequestName=“GetParameterNames”
2020-12-09T18:53:26.916Z [ERROR] 127.0.0.1: Session timeout; sessionTimestamp=1607539976128 deviceId=“00040E-FRITZ%21Box-3810D5697542”

LOOP2

2020-12-09T18:55:49.017Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Inform; cpeRequestId=“100” informEvent=“4 VALUE CHANGE,1 BOOT,0 BOOTSTRAP” informRetryCount=0
2020-12-09T18:55:49.023Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100000” acsRequestName=“FactoryReset”
2020-12-09T18:55:49.204Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100200” acsRequestName=“GetParameterNames”
2020-12-09T18:55:49.219Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100201” acsRequestName=“GetParameterNames”
2020-12-09T18:55:49.240Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100202” acsRequestName=“GetParameterNames”
2020-12-09T18:55:49.267Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100203” acsRequestName=“GetParameterNames”
2020-12-09T18:55:49.282Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100204” acsRequestName=“GetParameterNames”
2020-12-09T18:55:49.289Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100205” acsRequestName=“GetParameterNames”
2020-12-09T18:55:49.337Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100206” acsRequestName=“GetParameterNames”
2020-12-09T18:55:49.343Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100207” acsRequestName=“GetParameterValues”
2020-12-09T18:55:49.393Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100208” acsRequestName=“GetParameterNames”
2020-12-09T18:55:49.442Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648dc0b100209” acsRequestName=“GetParameterNames”
2020-12-09T18:56:19.443Z [ERROR] 127.0.0.1: Session timeout; sessionTimestamp=1607540149008 deviceId=“00040E-FRITZ%21Box-3810D5697542”

TASK removed

2020-12-09T18:58:46.189Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Inform; cpeRequestId=“100” informEvent=“4 VALUE CHANGE,1 BOOT,0 BOOTSTRAP” informRetryCount=0
2020-12-09T18:58:46.209Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250100” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.266Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250101” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.287Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250102” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.314Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250103” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.329Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250104” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.336Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250105” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.384Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250106” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.391Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250107” acsRequestName=“GetParameterValues”
2020-12-09T18:58:46.440Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250108” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.489Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250109” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.538Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf25010a” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.544Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf25010b” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.554Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf25010c” acsRequestName=“GetParameterValues”
2020-12-09T18:58:46.605Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf25010d” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.615Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf25010e” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.663Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf25010f” acsRequestName=“GetParameterValues”
2020-12-09T18:58:46.722Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250110” acsRequestName=“GetParameterNames”
2020-12-09T18:58:46.753Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250111” acsRequestName=“GetParameterNames”
2020-12-09T18:58:49.076Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250112” acsRequestName=“GetParameterNames”
2020-12-09T18:58:49.320Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250113” acsRequestName=“GetParameterNames”
2020-12-09T18:58:49.499Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250114” acsRequestName=“GetParameterValues”
2020-12-09T18:58:49.568Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250115” acsRequestName=“AddObject”
2020-12-09T18:58:49.593Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250116” acsRequestName=“GetParameterValues”
2020-12-09T18:58:49.624Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250117” acsRequestName=“SetParameterValues”
2020-12-09T18:58:49.939Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250118” acsRequestName=“GetParameterNames”
2020-12-09T18:58:50.669Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf250119” acsRequestName=“SetParameterValues”
2020-12-09T18:58:50.806Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf25011a” acsRequestName=“GetParameterNames”
2020-12-09T18:58:50.882Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf25011b” acsRequestName=“GetParameterValues”
2020-12-09T18:58:50.981Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf25011c” acsRequestName=“GetParameterValues”
2020-12-09T18:58:51.034Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648debf25011d” acsRequestName=“SetParameterValues”
2020-12-09T18:59:20.212Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Inform; cpeRequestId=“101” informEvent=“4 VALUE CHANGE” informRetryCount=0
2020-12-09T18:59:59.397Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-444E6D6FACE4: Inform; cpeRequestId=“2179” informEvent=“2 PERIODIC” informRetryCount=0
2020-12-09T18:59:59.414Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-444E6D6FACE4: ACS request; acsRequestId=“17648dfdd1b0100” acsRequestName=“GetParameterValues”
2020-12-09T19:03:25.901Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-444E6DA82E4F: Inform; cpeRequestId=“1616” informEvent=“2 PERIODIC” informRetryCount=0
2020-12-09T19:03:25.915Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-444E6DA82E4F: ACS request; acsRequestId=“17648e303c70100” acsRequestName=“GetParameterValues”
2020-12-09T19:03:51.453Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Inform; cpeRequestId=“102” informEvent=“2 PERIODIC” informRetryCount=0
2020-12-09T19:03:51.471Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648e367680100” acsRequestName=“GetParameterNames”
2020-12-09T19:03:51.495Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648e367680101” acsRequestName=“GetParameterNames”
2020-12-09T19:03:51.546Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648e367680102” acsRequestName=“GetParameterValues”
2020-12-09T19:03:51.571Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648e367680103” acsRequestName=“GetParameterNames”
2020-12-09T19:03:51.577Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648e367680104” acsRequestName=“GetParameterValues”
2020-12-09T19:03:51.599Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648e367680105” acsRequestName=“GetParameterNames”
2020-12-09T19:03:51.605Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648e367680106” acsRequestName=“GetParameterNames”
2020-12-09T19:03:51.615Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648e367680107” acsRequestName=“GetParameterNames”
2020-12-09T19:03:52.661Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17648e367680108” acsRequestName=“GetParameterValues”

zaidka · December 12, 2020, 10:55pm

Try the latest master branch. It should resolve this issue (for the most part). Let me explain:

The issue here seems to be that the CPE is disconnecting after the FactoryReset command and before the TR-069 session is considered to be successfully terminated. Hence the session eventually times out and Genie simply forgets all updates that took place during the session. That is why you get repeating factory reset commands. The latest patches address this by committing the session state even if the session does not terminate successfully.

I would argue that this is a CPE bug as well. While the ACS should tolerate unsuccessful session termination, the client should not exploit measures that are clearly meant for handling exceptional cases in its normal operation. But regardless, as per the spec:

The CPE MUST initiate the factory reset procedure only after successful completion of the Session.

Although I hate to rely on a strict literal interpretation of the spec to get the point across. The spec does seem to be vague and potentially even contradictory at times when it comes to the behavior around successful vs unsuccessful sessions.

Unfortunately that may not be possible. What if there are other tasks in the queue? And what about the presets that it still needs to process after competing the tasks?

mjducharme · December 13, 2020, 2:45am

I think you meant “considered to be unsuccessfully terminated”, not “successfully”.

olebowle · December 14, 2020, 10:11am

Thanks, the spec seems pretty clear on that point. I’ll try contacting the vendor regarding this issue.

In the meantime I tried the master branch. The task is deleted and a fault is created, when the session times out. Unfortunately, approximately three minutes later on the next BOOTSTRAP (09:15:30.152Z), GenieACS won’t retry the fault/provision. It answers with InformResponse and afterwards with “No Content”. Instead, I would expect GenieACS to retry the fault/provision.

Luckily, 15 minutes later (09:30:34.539Z) the CPE sends a VALUE CHANGE, after which GenieACS runs the provision and clears the fault. Generally, the devices won’t perform periodic informs after factory reset. Thus, it may happen that the fault/provision won’t be re-run anytime soon. This would potentially leave the devices unprovisioned for a long time.

I guess what I’m asking is: Why is the fault/provision not retried on the next BOOTSTRAP (09:15:30.152Z)?

2020-12-14T09:12:49.797Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Inform; cpeRequestId=“100” informEvent=“4 VALUE CHANGE,1 BOOT,0 BOOTSTRAP” informRetryCount=0
2020-12-14T09:12:49.827Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420000” acsRequestName=“FactoryReset”
2020-12-14T09:12:50.036Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420200” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.272Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420201” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.316Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420202” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.358Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420203” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.379Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420204” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.390Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420205” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.442Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420206” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.451Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420207” acsRequestName=“GetParameterValues”
2020-12-14T09:12:50.519Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420208” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.570Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176608619420209” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.623Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17660861942020a” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.633Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17660861942020b” acsRequestName=“GetParameterNames”
2020-12-14T09:12:50.648Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“17660861942020c” acsRequestName=“GetParameterValues”
2020-12-14T09:13:20.652Z [ERROR] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Session timeout; sessionTimestamp=1607937169730
2020-12-14T09:13:20.653Z [WARN] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Channel has faulted; channel=“default” retries=0 faultCode=“session_terminated” faultMessage=“The TR-069 session was unsuccessfully terminated”

2020-12-14T09:15:30.152Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Inform; cpeRequestId=“100” informEvent=“4 VALUE CHANGE,1 BOOT,0 BOOTSTRAP” informRetryCount=0

2020-12-14T09:30:34.539Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Inform; cpeRequestId=“101” informEvent=“4 VALUE CHANGE” informRetryCount=0
2020-12-14T09:30:34.551Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40000” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.567Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40001” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.588Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40002” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.613Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40003” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.625Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40004” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.631Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40005” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.680Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40006” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.686Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40007” acsRequestName=“GetParameterValues”
2020-12-14T09:30:34.737Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40008” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.786Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40009” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.838Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a4000a” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.848Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a4000b” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.861Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a4000c” acsRequestName=“GetParameterValues”
2020-12-14T09:30:34.913Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a4000d” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.933Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a4000e” acsRequestName=“GetParameterNames”
2020-12-14T09:30:34.987Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a4000f” acsRequestName=“GetParameterValues”
2020-12-14T09:30:35.045Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40010” acsRequestName=“GetParameterNames”
2020-12-14T09:30:35.092Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40011” acsRequestName=“GetParameterNames”
2020-12-14T09:30:35.826Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40012” acsRequestName=“GetParameterNames”
2020-12-14T09:30:35.954Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40013” acsRequestName=“GetParameterNames”
2020-12-14T09:30:36.081Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40014” acsRequestName=“GetParameterValues”
2020-12-14T09:30:36.167Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40015” acsRequestName=“AddObject”
2020-12-14T09:30:36.178Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40016” acsRequestName=“GetParameterValues”
2020-12-14T09:30:36.205Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40017” acsRequestName=“SetParameterValues”
2020-12-14T09:30:36.502Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40018” acsRequestName=“GetParameterNames”
2020-12-14T09:30:37.175Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a40019” acsRequestName=“SetParameterValues”
2020-12-14T09:30:37.313Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a4001a” acsRequestName=“GetParameterNames”
2020-12-14T09:30:37.389Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a4001b” acsRequestName=“GetParameterValues”
2020-12-14T09:30:37.448Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a4001c” acsRequestName=“GetParameterValues”
2020-12-14T09:30:37.501Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: ACS request; acsRequestId=“176609658a4001d” acsRequestName=“SetParameterValues”
2020-12-14T09:31:04.576Z [INFO] 127.0.0.1 00040E-FRITZ%21Box-3810D5697542: Inform; cpeRequestId=“102” informEvent=“4 VALUE CHANGE” informRetryCount=0

JonasGhost · March 3, 2021, 4:43pm

I switched from 1.2.2 to 1.2.4 and now I get very often the error message:
“The TR-069 session was unsuccessfully terminated”

I have not started debugging.

Instance A runs behind a nginx reverse proxy (https), with zyxel devices. There I get this error message.

Instance B is directly accessed over HTTP. There I did not see this message jet. It does only have 2 Clients, a phone and a FRITZ!Box

JonasGhost · March 4, 2021, 8:05pm

@olebowle
Is your GenieACS instance behind a reverse proxy?

olebowle · March 8, 2021, 10:43am

Yes, we do reverse proxy GenieACS and thus, terminate TLS of the CWMP session with Apache. On localhost it is unencrypted for debugging purpose.

JonasGhost · March 8, 2021, 11:10am

Ok, it looks like, there is a problem with reverse proxies.
I have created for this issue a own topic:

It appears from 1.2.3 upwards.

kulakoff · April 12, 2021, 12:53pm

I have a problem, when using a Nnginx proxy pass to local cwmp host I get an error:

Channel has faulted; channel = “default” retries = 0 faultCode = “session_terminated” faultMessage = “The TR-069 session was unsuccessfully terminated”

Topic		Replies	Views
Auto-provisioning and Presets 1.2.9 not working	13	1257	November 21, 2022
Presets and events	2	1479	August 10, 2021
"too_many_cycles" "Too many provision cycles" Faults	11	460	April 27, 2023
Is the GenieACS provisioning script example flawed?	2	1850	May 7, 2020
Genieacs-sim: event code	0	291	March 31, 2023

FactoryReset Loop

LOOP0

LOOP1

LOOP2

TASK removed

Related Topics