No response from cwmp after time on inform request

1

We just upgraded from 1.2.0-beta.0 to 1.2.0 but for some reason some CPEs not getting their Inform response thus they are falsely showing as offline. The access.log shows an incoming inform (2 PERIODIC) but 30s after that a session timeout is logged. Our DrayTek routers have a button/function to test the connection but they don’t show a response from ACS if I send an inform manually. Restarting the cwmp service fixes it until it happens again.

Edit: Here is the debug.yaml of a request on an affected device. After that the session timeout occurs and the request repeats:

---
event: incoming HTTP request
timestamp: 2020-09-07T13:07:24.348Z
remoteAddress: <CPE IP>
deviceId: 001DAA-Vigor2762Vac-001DAA74BE98
connection: 2020-09-07T13:07:24.349Z
localPort: 7547
method: POST
url: /
headers:
  accept: "*/*"
  user-agent: Vigor TR-069 CPE
  content-type: text/xml; charset=utf-8
  content-length: "2353"
  host: <ACS HOST>:7547
  connection: Keep-Alive
  soapaction: ""
body: "<soap:Envelope \r

  xmlns:soap=\"http://schemas.xmlsoap.org/soap/envelope/\" \r

  xmlns:soap-enc=\"http://schemas.xmlsoap.org/soap/encoding/\" \r

  xmlns:cwmp=\"urn:dslforum-org:cwmp-1-0\" \r

  xmlns:xsd=\"http://www.w3.org/2001/XMLSchema\" \r

  xmlns:xsi=\"http://www.w3.org/2001/XMLSchema-instance\">\r

  <soap:Header>\r

  <cwmp:ID soap:mustUnderstand=\"1\">24245</cwmp:ID>\r

  </soap:Header>\r

  <soap:Body>\r

  <cwmp:Inform>\r

  <DeviceId>\r

  <Manufacturer>DrayTek</Manufacturer>\r

  <OUI>001DAA</OUI>\r

  <ProductClass>Vigor2762Vac</ProductClass>\r

  <SerialNumber>001DAA74BE98</SerialNumber>\r

  </DeviceId>\r

  <Event soap-enc:arrayType=\"cwmp:EventStruct[1]\">\r

  <EventStruct>\r

  <EventCode>2 PERIODIC</EventCode>\r

  <CommandKey></CommandKey>\r

  </EventStruct>\r

  </Event>\r

  <MaxEnvelopes>1</MaxEnvelopes>\r

  <CurrentTime>2020-09-07T15:07:22</CurrentTime>\r

  <RetryCount>0</RetryCount>\r

  <ParameterList soap-enc:arrayType=\"cwmp:ParameterValueStruct[8]\">\r

  <ParameterValueStruct>\r

  <Name>InternetGatewayDevice.DeviceInfo.SpecVersion</Name>\r

  <Value xsi:type=\"xsd:string\">1.0</Value>\r

  </ParameterValueStruct>\r

  <ParameterValueStruct>\r

  <Name>InternetGatewayDevice.DeviceInfo.HardwareVersion</Name>\r

  <Value xsi:type=\"xsd:string\">6</Value>\r

  </ParameterValueStruct>\r

  <ParameterValueStruct>\r

  <Name>InternetGatewayDevice.DeviceInfo.SoftwareVersion</Name>\r

  <Value xsi:type=\"xsd:string\">3.9.2_STD</Value>\r

  </ParameterValueStruct>\r

  <ParameterValueStruct>\r

  <Name>InternetGatewayDevice.DeviceInfo.ProvisioningCode</Name>\r

  <Value xsi:type=\"xsd:string\"></Value>\r

  </ParameterValueStruct>\r

  <ParameterValueStruct>\r

  <Name>InternetGatewayDevice.ManagementServer.ConnectionRequestURL</Name>\r

  <Value
  xsi:type=\"xsd:string\">http://<CPE IP>:8069/cwm/CRN.html</Value>\r

  </ParameterValueStruct>\r

  <ParameterValueStruct>\r

  <Name>InternetGatewayDevice.ManagementServer.ParameterKey</Name>\r

  <Value xsi:type=\"xsd:string\"></Value>\r

  </ParameterValueStruct>\r

  <ParameterValueStruct>\r

  <Name>InternetGatewayDevice.DeviceInfo.AuthKey</Name>\r

  <Value xsi:type=\"xsd:string\">019a39cf3d6e65b3b0cb9584acd7ac78</Value>\r

  </ParameterValueStruct>\r

  <ParameterValueStruct>\r

  <Name>InternetGatewayDevice.WANDevice.1.WANConnectionDevice.1.WANPPPConnect\
  ion.1.ExternalIPAddress</Name>\r

  <Value xsi:type=\"xsd:string\"><CPE IP></Value>\r

  </ParameterValueStruct>\r

  </ParameterList>\r

  </cwmp:Inform>\r

  </soap:Body>\r

  </soap:Envelope>\r

  \                                                  "
---
event: outgoing HTTP response
timestamp: 2020-09-07T13:07:24.353Z
remoteAddress: <CPE IP>
deviceId: 001DAA-Vigor2762Vac-001DAA74BE98
connection: 2020-09-07T13:07:24.349Z
statusCode: 200
headers:
  content-length: 525
  server: GenieACS/1.2.0+20200901150338
  soapserver: GenieACS/1.2.0+20200901150338
  content-type: text/xml; charset="utf-8"
  set-cookie: session=526857854a479606
body: >-
  <?xml version="1.0" encoding="UTF-8"?>

  <soap-env:Envelope xmlns:soap-enc="http://schemas.xmlsoap.org/soap/encoding/" xmlns:soap-env="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:cwmp="urn:dslforum-org:cwmp-1-0"><soap-env:Header><cwmp:ID soap-env:mustUnderstand="1">24245</cwmp:ID></soap-env:Header><soap-env:Body><cwmp:InformResponse><MaxEnvelopes>1</MaxEnvelopes></cwmp:InformResponse></soap-env:Body></soap-env:Envelope>
2

Can you do a wireshark or tcpdump capture to see if the CPE sends any request after the InformResponse from the ACS?

3

I will try to capture it and get back here. After looking into it more closely I saw for myself that my report isn’t sufficient enough ;). Currently I’m using 1.2.1 with the 1.2.0-b0 cwmp and ext-script patches as a Workaround - thanks to your modular design.

4

I just wanted to capture it and built the current master to run it and wait for lost connections. Seems like it’s fixed. Even minor problems happening from time to time where the CPE reported an “401 unauthorized” which could be reestablished by a summon (6 CONNECTION REQUEST) are gone.