View Issue Details

IDProjectCategoryView StatusLast Update
0000350easycwmpBugpublic2018-10-01 09:01
Reporterokraits Assigned To 
PriorityhighSeveritymajorReproducibilityalways
Status newResolutionopen 
OSOpenWRTOS VersionLEDE 17.01 
Summary0000350: easycwmp doesn't send a DownloadResponse for the second of two consecutive downloads
DescriptionIf two download requests appear within a short period of time, then easycwmp doesn't send a DownloadResponse for the second download request.

Thus the ACS thinks that the download request wasn't successful and retries the whole session.
Steps To ReproduceSend two download requests to easycwmp closely one after the other.
Additional InformationAttached you find the ACS log and the easycwmp log.
TagsNo tags attached.

Activities

okraits

2018-08-10 15:02

reporter  

easycwmp.log (11,464 bytes)   
Fri Aug 10 14:25:55 2018 daemon.notice easycwmpd: add event '2 PERIODIC'
Fri Aug 10 14:25:55 2018 daemon.notice easycwmpd: start session
Fri Aug 10 14:25:55 2018 daemon.notice easycwmpd: configured acs url https://host:7547/genieacs
Fri Aug 10 14:25:55 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:25:56 2018 daemon.notice easycwmpd: external: execute inform parameter 
Fri Aug 10 14:25:57 2018 daemon.notice easycwmpd: send Inform
Fri Aug 10 14:25:57 2018 daemon.notice easycwmpd: receive InformResponse from the ACS
Fri Aug 10 14:25:57 2018 daemon.notice easycwmpd: send empty message to the ACS
Fri Aug 10 14:25:57 2018 daemon.notice easycwmpd: receive empty message from the ACS
Fri Aug 10 14:25:57 2018 daemon.notice easycwmpd: external: execute apply service 
Fri Aug 10 14:25:58 2018 daemon.notice easycwmpd: external script exit
Fri Aug 10 14:25:58 2018 daemon.notice easycwmpd: end session success
Fri Aug 10 14:26:55 2018 daemon.notice easycwmpd: add event '2 PERIODIC'
Fri Aug 10 14:26:55 2018 daemon.notice easycwmpd: start session
Fri Aug 10 14:26:55 2018 daemon.notice easycwmpd: configured acs url https://host:7547/genieacs
Fri Aug 10 14:26:55 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:26:56 2018 daemon.notice easycwmpd: external: execute inform parameter 
Fri Aug 10 14:26:57 2018 daemon.notice easycwmpd: send Inform
Fri Aug 10 14:26:57 2018 daemon.notice easycwmpd: receive InformResponse from the ACS
Fri Aug 10 14:26:57 2018 daemon.notice easycwmpd: send empty message to the ACS
Fri Aug 10 14:26:57 2018 daemon.notice easycwmpd: received Download method from the ACS
Fri Aug 10 14:26:57 2018 daemon.notice easycwmpd: add download: delay = 0 sec, url = https://host:7567/test, FileType = '12 Other File', CommandKey = '16523cdd9bd0000'
Fri Aug 10 14:26:57 2018 daemon.notice easycwmpd: send DownloadResponse to the ACS
Fri Aug 10 14:26:58 2018 daemon.notice easycwmpd: received Download method from the ACS
Fri Aug 10 14:26:58 2018 daemon.notice easycwmpd: add download: delay = 0 sec, url = https://host:7567/test_1533903958.1886573.sh, FileType = '11 Shell Script', CommandKey = '16523cdd9bd0100'
Fri Aug 10 14:26:58 2018 daemon.notice easycwmpd: send DownloadResponse to the ACS
Fri Aug 10 14:27:05 2018 daemon.notice easycwmpd: add download: delay = -8 sec, url = https://host:7567/test, FileType = '12 Other File', CommandKey = '16523cdd9bd0000'
Fri Aug 10 14:27:05 2018 daemon.notice easycwmpd: add download: delay = -7 sec, url = https://host:7567/test_1533903958.1886573.sh, FileType = '11 Shell Script', CommandKey = '16523cdd9bd0100'
Fri Aug 10 14:27:05 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:27:06 2018 daemon.notice easycwmpd: init periodic inform: reference time = n/a, interval = 60
Fri Aug 10 14:27:06 2018 daemon.notice easycwmpd: daemon started
Fri Aug 10 14:27:06 2018 daemon.notice easycwmpd: external: execute inform device_id 
Fri Aug 10 14:27:06 2018 daemon.notice easycwmpd: external script exit
Fri Aug 10 14:27:06 2018 daemon.notice easycwmpd: add event '1 BOOT'
Fri Aug 10 14:27:06 2018 daemon.notice easycwmpd: interface eth0 has ip 10.2.30.1
Fri Aug 10 14:27:06 2018 daemon.notice easycwmpd: http server initialized
Fri Aug 10 14:27:06 2018 daemon.notice easycwmpd: entering main loop
Fri Aug 10 14:27:06 2018 daemon.notice easycwmpd: start download url = https://host:7567/test, FileType = '12 Other File', CommandKey = '16523cdd9bd0000'
Fri Aug 10 14:27:06 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:27:07 2018 daemon.notice easycwmpd: external: execute download
Fri Aug 10 14:27:08 2018 daemon.notice easycwmpd: add event '7 TRANSFER COMPLETE'
Fri Aug 10 14:27:08 2018 daemon.notice easycwmpd: add event 'M Download'
Fri Aug 10 14:27:08 2018 daemon.notice easycwmpd: external: execute apply download 12 Other File
Fri Aug 10 14:27:15 2018 daemon.notice easycwmpd: add download: delay = -17 sec, url = https://host:7567/test_1533903958.1886573.sh, FileType = '', CommandKey = '16523cdd9bd0100'
Fri Aug 10 14:27:15 2018 daemon.notice easycwmpd: add event '1 BOOT'
Fri Aug 10 14:27:15 2018 daemon.notice easycwmpd: add event '7 TRANSFER COMPLETE'
Fri Aug 10 14:27:15 2018 daemon.notice easycwmpd: add event 'M Download'
Fri Aug 10 14:27:15 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:27:16 2018 daemon.notice easycwmpd: init periodic inform: reference time = n/a, interval = 60
Fri Aug 10 14:27:16 2018 daemon.notice easycwmpd: daemon started
Fri Aug 10 14:27:16 2018 daemon.notice easycwmpd: external: execute inform device_id 
Fri Aug 10 14:27:16 2018 daemon.notice easycwmpd: external script exit
Fri Aug 10 14:27:16 2018 daemon.notice easycwmpd: add event '1 BOOT'
Fri Aug 10 14:27:16 2018 daemon.notice easycwmpd: interface eth0 has ip 10.2.30.1
Fri Aug 10 14:27:16 2018 daemon.notice easycwmpd: http server initialized
Fri Aug 10 14:27:16 2018 daemon.notice easycwmpd: entering main loop
Fri Aug 10 14:27:16 2018 daemon.notice easycwmpd: start download url = https://host:7567/test_1533903958.1886573.sh, FileType = '', CommandKey = '16523cdd9bd0100'
Fri Aug 10 14:27:16 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:27:17 2018 daemon.notice easycwmpd: external: execute download
Fri Aug 10 14:27:17 2018 daemon.notice easycwmpd: add event '7 TRANSFER COMPLETE'
Fri Aug 10 14:27:17 2018 daemon.notice easycwmpd: add event 'M Download'
Fri Aug 10 14:27:17 2018 daemon.notice easycwmpd: download error: 'Download failure'
Fri Aug 10 14:27:17 2018 daemon.notice easycwmpd: external script exit
Fri Aug 10 14:27:17 2018 daemon.notice easycwmpd: start session
Fri Aug 10 14:27:17 2018 daemon.notice easycwmpd: configured acs url https://host:7547/genieacs
Fri Aug 10 14:27:17 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:27:18 2018 daemon.notice easycwmpd: external: execute inform parameter 
Fri Aug 10 14:27:18 2018 daemon.notice easycwmpd: send Inform
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: receive InformResponse from the ACS
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: send RPC ACS TransferComplete
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: receive TransferCompleteResponse from the ACS
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: send RPC ACS TransferComplete
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: receive TransferCompleteResponse from the ACS
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: send empty message to the ACS
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: received Download method from the ACS
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: add download: delay = 0 sec, url = https://host:7567/test, FileType = '12 Other File', CommandKey = '16523ce2d060000'
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: send DownloadResponse to the ACS
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: received Download method from the ACS
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: add download: delay = 0 sec, url = https://host:7567/test_1533903958.1886573.sh, FileType = '11 Shell Script', CommandKey = '16523ce2d060100'
Fri Aug 10 14:27:19 2018 daemon.notice easycwmpd: send DownloadResponse to the ACS
Fri Aug 10 14:27:26 2018 daemon.notice easycwmpd: add download: delay = -7 sec, url = https://host:7567/test, FileType = '12 Other File', CommandKey = '16523ce2d060000'
Fri Aug 10 14:27:26 2018 daemon.notice easycwmpd: add download: delay = -7 sec, url = https://host:7567/test_1533903958.1886573.sh, FileType = '11 Shell Script', CommandKey = '16523ce2d060100'
Fri Aug 10 14:27:26 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: init periodic inform: reference time = n/a, interval = 60
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: daemon started
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: external: execute inform device_id 
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: external script exit
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: add event '1 BOOT'
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: interface eth0 has ip 10.2.30.1
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: http server initialized
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: entering main loop
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: start download url = https://host:7567/test, FileType = '12 Other File', CommandKey = '16523ce2d060000'
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: external: execute download
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: add event '7 TRANSFER COMPLETE'
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: add event 'M Download'
Fri Aug 10 14:27:27 2018 daemon.notice easycwmpd: external: execute apply download 12 Other File
Fri Aug 10 14:27:35 2018 daemon.notice easycwmpd: add download: delay = -16 sec, url = https://host:7567/test_1533903958.1886573.sh, FileType = '', CommandKey = '16523ce2d060100'
Fri Aug 10 14:27:35 2018 daemon.notice easycwmpd: add event '1 BOOT'
Fri Aug 10 14:27:35 2018 daemon.notice easycwmpd: add event '7 TRANSFER COMPLETE'
Fri Aug 10 14:27:35 2018 daemon.notice easycwmpd: add event 'M Download'
Fri Aug 10 14:27:35 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:27:36 2018 daemon.notice easycwmpd: init periodic inform: reference time = n/a, interval = 60
Fri Aug 10 14:27:36 2018 daemon.notice easycwmpd: daemon started
Fri Aug 10 14:27:36 2018 daemon.notice easycwmpd: external: execute inform device_id 
Fri Aug 10 14:27:36 2018 daemon.notice easycwmpd: external script exit
Fri Aug 10 14:27:36 2018 daemon.notice easycwmpd: add event '1 BOOT'
Fri Aug 10 14:27:36 2018 daemon.notice easycwmpd: interface eth0 has ip 10.2.30.1
Fri Aug 10 14:27:36 2018 daemon.notice easycwmpd: http server initialized
Fri Aug 10 14:27:36 2018 daemon.notice easycwmpd: entering main loop
Fri Aug 10 14:27:36 2018 daemon.notice easycwmpd: start download url = https://host:7567/test_1533903958.1886573.sh, FileType = '', CommandKey = '16523ce2d060100'
Fri Aug 10 14:27:36 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:27:37 2018 daemon.notice easycwmpd: external: execute download
Fri Aug 10 14:27:37 2018 daemon.notice easycwmpd: add event '7 TRANSFER COMPLETE'
Fri Aug 10 14:27:37 2018 daemon.notice easycwmpd: add event 'M Download'
Fri Aug 10 14:27:37 2018 daemon.notice easycwmpd: download error: 'Download failure'
Fri Aug 10 14:27:37 2018 daemon.notice easycwmpd: external script exit
Fri Aug 10 14:27:37 2018 daemon.notice easycwmpd: start session
Fri Aug 10 14:27:37 2018 daemon.notice easycwmpd: configured acs url https://host:7547/genieacs
Fri Aug 10 14:27:37 2018 daemon.notice easycwmpd: external script init
Fri Aug 10 14:27:38 2018 daemon.notice easycwmpd: external: execute inform parameter 
Fri Aug 10 14:27:38 2018 daemon.notice easycwmpd: send Inform
Fri Aug 10 14:27:39 2018 daemon.notice easycwmpd: LibCurl Error: The requested URL returned error: 502 Bad Gateway
Fri Aug 10 14:27:39 2018 daemon.notice easycwmpd: sending http message failed
Fri Aug 10 14:27:39 2018 daemon.notice easycwmpd: sending Inform failed
Fri Aug 10 14:27:39 2018 daemon.notice easycwmpd: external: execute apply service 
Fri Aug 10 14:27:39 2018 daemon.notice easycwmpd: external script exit
Fri Aug 10 14:27:39 2018 daemon.notice easycwmpd: end session failed
Fri Aug 10 14:27:39 2018 daemon.notice easycwmpd: retry session in 7 sec, RetryCount = 1
easycwmp.log (11,464 bytes)   

okraits

2018-08-10 15:02

reporter  

acs.log (21,647 bytes)   
# REQUEST Fri Aug 10 2018 14:25:57 GMT+0200 (CEST)
{"host":"host","connection":"close","content-length":"3065","user-agent":"easycwmp","content-type":"text/xml; charset=\"utf-8\""}
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
 <soap_env:Envelope
xmlns:soap_env="http://schemas.xmlsoap.org/soap/envelope/"
xmlns:soap_enc="http://schemas.xmlsoap.org/soap/encoding/"
xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:cwmp="urn:dslforum-org:cwmp-1-2">
  <soap_env:Header>
   <cwmp:ID soap_env:mustUnderstand="1">354</cwmp:ID>
  </soap_env:Header>
  <soap_env:Body>
   <cwmp:Inform>
    <DeviceId>
     <Manufacturer>WE</Manufacturer>
     <OUI>000000</OUI>
     <ProductClass>Homer</ProductClass>
     <SerialNumber>serial</SerialNumber>
    </DeviceId>
    <Event soap_enc:arrayType="cwmp:EventStruct[1]">
     <EventStruct>
      <EventCode>2 PERIODIC</EventCode>
      <CommandKey />
     </EventStruct>
    </Event>
    <MaxEnvelopes>1</MaxEnvelopes>
    <CurrentTime>2018-08-10T14:25:56+02:00</CurrentTime>
    <RetryCount>0</RetryCount>
    <ParameterList soap_enc:arrayType="cwmp:ParameterValueStruct[11]">
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.HardwareVersion</Name>
      <Value xsi:type="xsd:string">1.0</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.Manufacturer</Name>
      <Value xsi:type="xsd:string">WE</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.ManufacturerOUI</Name>
      <Value xsi:type="xsd:string">000000</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.ProductClass</Name>
      <Value xsi:type="xsd:string">Homer</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.ProvisioningCode</Name>
      <Value xsi:type="xsd:string"></Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.SerialNumber</Name>
      <Value xsi:type="xsd:string">serial</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.SoftwareVersion</Name>
      <Value xsi:type="xsd:string">1.0</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.SpecVersion</Name>
      <Value xsi:type="xsd:string">1.0</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.ManagementServer.ConnectionRequestURL</Name>
      <Value xsi:type="xsd:string">http://10.2.30.1:7547/</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.ManagementServer.ParameterKey</Name>
      <Value xsi:type="xsd:string"></Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.WANDevice.1.WANConnectionDevice.1.WANIPConnection.1.ExternalIPAddress</Name>
      <Value xsi:type="xsd:string"></Value>
     </ParameterValueStruct>
    </ParameterList>
   </cwmp:Inform>
  </soap_env:Body>
 </soap_env:Envelope>


# RESPONSE Fri Aug 10 2018 14:25:57 GMT+0200 (CEST)
{"Server":"GenieACS/1.1.1","SOAPServer":"GenieACS/1.1.1","Content-Type":"text/xml; charset=\"utf-8\"","Set-Cookie":"session=73ac121c4940ee9a"}
<?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-2"><soap-env:Header><cwmp:ID soap-env:mustUnderstand="1">354</cwmp:ID></soap-env:Header><soap-env:Body><cwmp:InformResponse><MaxEnvelopes>1</MaxEnvelopes></cwmp:InformResponse></soap-env:Body></soap-env:Envelope>


# REQUEST Fri Aug 10 2018 14:25:57 GMT+0200 (CEST)
{"host":"host","connection":"close","content-length":"0","cookie":"session=73ac121c4940ee9a","user-agent":"easycwmp","content-type":"text/xml; charset=\"utf-8\""}


# RESPONSE Fri Aug 10 2018 14:25:57 GMT+0200 (CEST)
{"Server":"GenieACS/1.1.1","SOAPServer":"GenieACS/1.1.1","Connection":"close"}


# REQUEST Fri Aug 10 2018 14:26:57 GMT+0200 (CEST)
{"host":"host","connection":"close","content-length":"3065","user-agent":"easycwmp","content-type":"text/xml; charset=\"utf-8\""}
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
 <soap_env:Envelope
xmlns:soap_env="http://schemas.xmlsoap.org/soap/envelope/"
xmlns:soap_enc="http://schemas.xmlsoap.org/soap/encoding/"
xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:cwmp="urn:dslforum-org:cwmp-1-2">
  <soap_env:Header>
   <cwmp:ID soap_env:mustUnderstand="1">355</cwmp:ID>
  </soap_env:Header>
  <soap_env:Body>
   <cwmp:Inform>
    <DeviceId>
     <Manufacturer>WE</Manufacturer>
     <OUI>000000</OUI>
     <ProductClass>Homer</ProductClass>
     <SerialNumber>serial</SerialNumber>
    </DeviceId>
    <Event soap_enc:arrayType="cwmp:EventStruct[1]">
     <EventStruct>
      <EventCode>2 PERIODIC</EventCode>
      <CommandKey />
     </EventStruct>
    </Event>
    <MaxEnvelopes>1</MaxEnvelopes>
    <CurrentTime>2018-08-10T14:26:56+02:00</CurrentTime>
    <RetryCount>0</RetryCount>
    <ParameterList soap_enc:arrayType="cwmp:ParameterValueStruct[11]">
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.HardwareVersion</Name>
      <Value xsi:type="xsd:string">1.0</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.Manufacturer</Name>
      <Value xsi:type="xsd:string">WE</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.ManufacturerOUI</Name>
      <Value xsi:type="xsd:string">000000</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.ProductClass</Name>
      <Value xsi:type="xsd:string">Homer</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.ProvisioningCode</Name>
      <Value xsi:type="xsd:string"></Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.SerialNumber</Name>
      <Value xsi:type="xsd:string">serial</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.SoftwareVersion</Name>
      <Value xsi:type="xsd:string">1.0</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.SpecVersion</Name>
      <Value xsi:type="xsd:string">1.0</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.ManagementServer.ConnectionRequestURL</Name>
      <Value xsi:type="xsd:string">http://10.2.30.1:7547/</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.ManagementServer.ParameterKey</Name>
      <Value xsi:type="xsd:string"></Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.WANDevice.1.WANConnectionDevice.1.WANIPConnection.1.ExternalIPAddress</Name>
      <Value xsi:type="xsd:string"></Value>
     </ParameterValueStruct>
    </ParameterList>
   </cwmp:Inform>
  </soap_env:Body>
 </soap_env:Envelope>


# RESPONSE Fri Aug 10 2018 14:26:57 GMT+0200 (CEST)
{"Server":"GenieACS/1.1.1","SOAPServer":"GenieACS/1.1.1","Content-Type":"text/xml; charset=\"utf-8\"","Set-Cookie":"session=ff31495f7038ec82"}
<?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-2"><soap-env:Header><cwmp:ID soap-env:mustUnderstand="1">355</cwmp:ID></soap-env:Header><soap-env:Body><cwmp:InformResponse><MaxEnvelopes>1</MaxEnvelopes></cwmp:InformResponse></soap-env:Body></soap-env:Envelope>


# REQUEST Fri Aug 10 2018 14:26:57 GMT+0200 (CEST)
{"host":"host","connection":"close","content-length":"0","cookie":"session=ff31495f7038ec82","user-agent":"easycwmp","content-type":"text/xml; charset=\"utf-8\""}


# RESPONSE Fri Aug 10 2018 14:26:57 GMT+0200 (CEST)
{"Server":"GenieACS/1.1.1","SOAPServer":"GenieACS/1.1.1","Content-Type":"text/xml; charset=\"utf-8\""}
<?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-2"><soap-env:Header><cwmp:ID soap-env:mustUnderstand="1">16523cdd9bd0000</cwmp:ID></soap-env:Header><soap-env:Body><cwmp:Download><CommandKey>16523cdd9bd0000</CommandKey><FileType>12 Other File</FileType><URL>https://host:7567/test</URL><Username/><Password/><FileSize>14</FileSize><TargetFileName/><DelaySeconds>0</DelaySeconds><SuccessURL/><FailureURL/></cwmp:Download></soap-env:Body></soap-env:Envelope>


# REQUEST Fri Aug 10 2018 14:26:58 GMT+0200 (CEST)
{"host":"host","connection":"close","content-length":"678","cookie":"session=ff31495f7038ec82","user-agent":"easycwmp","content-type":"text/xml; charset=\"utf-8\"","soapaction":""}
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
 <soap_env:Envelope
xmlns:soap_env="http://schemas.xmlsoap.org/soap/envelope/"
xmlns:soap_enc="http://schemas.xmlsoap.org/soap/encoding/"
xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:cwmp="urn:dslforum-org:cwmp-1-2">
  <soap_env:Header>
   <cwmp:ID soap_env:mustUnderstand="1">16523cdd9bd0000</cwmp:ID>
  </soap_env:Header>
  <soap_env:Body>
   <cwmp:DownloadResponse>
    <Status>1</Status>
    <StartTime>0001-01-01T00:00:00Z</StartTime>
    <CompleteTime>0001-01-01T00:00:00Z</CompleteTime>
   </cwmp:DownloadResponse>
  </soap_env:Body>
 </soap_env:Envelope>


# RESPONSE Fri Aug 10 2018 14:26:58 GMT+0200 (CEST)
{"Server":"GenieACS/1.1.1","SOAPServer":"GenieACS/1.1.1","Content-Type":"text/xml; charset=\"utf-8\""}
<?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-2"><soap-env:Header><cwmp:ID soap-env:mustUnderstand="1">16523cdd9bd0100</cwmp:ID></soap-env:Header><soap-env:Body><cwmp:Download><CommandKey>16523cdd9bd0100</CommandKey><FileType>11 Shell Script</FileType><URL>https://host:7567/test_1533903958.1886573.sh</URL><Username/><Password/><FileSize>0</FileSize><TargetFileName/><DelaySeconds>0</DelaySeconds><SuccessURL/><FailureURL/></cwmp:Download></soap-env:Body></soap-env:Envelope>


# REQUEST Fri Aug 10 2018 14:27:19 GMT+0200 (CEST)
{"host":"host","connection":"close","content-length":"3420","user-agent":"easycwmp","content-type":"text/xml; charset=\"utf-8\""}
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
 <soap_env:Envelope
xmlns:soap_env="http://schemas.xmlsoap.org/soap/envelope/"
xmlns:soap_enc="http://schemas.xmlsoap.org/soap/encoding/"
xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:cwmp="urn:dslforum-org:cwmp-1-2">
  <soap_env:Header>
   <cwmp:ID soap_env:mustUnderstand="1">1</cwmp:ID>
  </soap_env:Header>
  <soap_env:Body>
   <cwmp:Inform>
    <DeviceId>
     <Manufacturer>WE</Manufacturer>
     <OUI>000000</OUI>
     <ProductClass>Homer</ProductClass>
     <SerialNumber>serial</SerialNumber>
    </DeviceId>
    <Event soap_enc:arrayType="cwmp:EventStruct[4]">
     <EventStruct>
      <EventCode>1 BOOT</EventCode>
      <CommandKey />
     </EventStruct>
     <EventStruct>
      <EventCode>7 TRANSFER COMPLETE</EventCode>
      <CommandKey />
     </EventStruct>
     <EventStruct>
      <EventCode>M Download</EventCode>
      <CommandKey>16523cdd9bd0000</CommandKey>
     </EventStruct>
     <EventStruct>
      <EventCode>M Download</EventCode>
      <CommandKey>16523cdd9bd0100</CommandKey>
     </EventStruct>
    </Event>
    <MaxEnvelopes>1</MaxEnvelopes>
    <CurrentTime>2018-08-10T14:27:18+02:00</CurrentTime>
    <RetryCount>0</RetryCount>
    <ParameterList soap_enc:arrayType="cwmp:ParameterValueStruct[11]">
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.HardwareVersion</Name>
      <Value xsi:type="xsd:string">1.0</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.Manufacturer</Name>
      <Value xsi:type="xsd:string">WE</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.ManufacturerOUI</Name>
      <Value xsi:type="xsd:string">000000</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.ProductClass</Name>
      <Value xsi:type="xsd:string">Homer</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.ProvisioningCode</Name>
      <Value xsi:type="xsd:string"></Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.SerialNumber</Name>
      <Value xsi:type="xsd:string">serial</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.SoftwareVersion</Name>
      <Value xsi:type="xsd:string">1.0</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.DeviceInfo.SpecVersion</Name>
      <Value xsi:type="xsd:string">1.0</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.ManagementServer.ConnectionRequestURL</Name>
      <Value xsi:type="xsd:string">http://10.2.30.1:7547/</Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.ManagementServer.ParameterKey</Name>
      <Value xsi:type="xsd:string"></Value>
     </ParameterValueStruct>
     <ParameterValueStruct>
      <Name>InternetGatewayDevice.WANDevice.1.WANConnectionDevice.1.WANIPConnection.1.ExternalIPAddress</Name>
      <Value xsi:type="xsd:string"></Value>
     </ParameterValueStruct>
    </ParameterList>
   </cwmp:Inform>
  </soap_env:Body>
 </soap_env:Envelope>


# RESPONSE Fri Aug 10 2018 14:27:19 GMT+0200 (CEST)
{"Server":"GenieACS/1.1.1","SOAPServer":"GenieACS/1.1.1","Content-Type":"text/xml; charset=\"utf-8\"","Set-Cookie":"session=672c8647267e015c"}
<?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-2"><soap-env:Header><cwmp:ID soap-env:mustUnderstand="1">1</cwmp:ID></soap-env:Header><soap-env:Body><cwmp:InformResponse><MaxEnvelopes>1</MaxEnvelopes></cwmp:InformResponse></soap-env:Body></soap-env:Envelope>


# REQUEST Fri Aug 10 2018 14:27:19 GMT+0200 (CEST)
{"host":"host","connection":"close","content-length":"784","cookie":"session=672c8647267e015c","user-agent":"easycwmp","content-type":"text/xml; charset=\"utf-8\"","soapaction":""}
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
 <soap_env:Envelope
xmlns:soap_env="http://schemas.xmlsoap.org/soap/envelope/"
xmlns:soap_enc="http://schemas.xmlsoap.org/soap/encoding/"
xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:cwmp="urn:dslforum-org:cwmp-1-2">
  <soap_env:Header>
   <cwmp:ID soap_env:mustUnderstand="1">2</cwmp:ID>
  </soap_env:Header>
  <soap_env:Body>
   <cwmp:TransferComplete>
    <CommandKey>16523cdd9bd0000</CommandKey>
    <FaultStruct>
     <FaultCode>0</FaultCode>
     <FaultString />
    </FaultStruct>
    <StartTime>2018-08-10T14:27:07+02:00</StartTime>
    <CompleteTime>2018-08-10T14:27:15+02:00</CompleteTime>
   </cwmp:TransferComplete>
  </soap_env:Body>
 </soap_env:Envelope>


# RESPONSE Fri Aug 10 2018 14:27:19 GMT+0200 (CEST)
{"Server":"GenieACS/1.1.1","SOAPServer":"GenieACS/1.1.1","Content-Type":"text/xml; charset=\"utf-8\""}
<?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-2"><soap-env:Header><cwmp:ID soap-env:mustUnderstand="1">2</cwmp:ID></soap-env:Header><soap-env:Body><cwmp:TransferCompleteResponse/></soap-env:Body></soap-env:Envelope>


# REQUEST Fri Aug 10 2018 14:27:19 GMT+0200 (CEST)
{"host":"host","connection":"close","content-length":"815","cookie":"session=672c8647267e015c","user-agent":"easycwmp","content-type":"text/xml; charset=\"utf-8\"","soapaction":""}
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
 <soap_env:Envelope
xmlns:soap_env="http://schemas.xmlsoap.org/soap/envelope/"
xmlns:soap_enc="http://schemas.xmlsoap.org/soap/encoding/"
xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:cwmp="urn:dslforum-org:cwmp-1-2">
  <soap_env:Header>
   <cwmp:ID soap_env:mustUnderstand="1">3</cwmp:ID>
  </soap_env:Header>
  <soap_env:Body>
   <cwmp:TransferComplete>
    <CommandKey>16523cdd9bd0100</CommandKey>
    <FaultStruct>
     <FaultCode>9010</FaultCode>
     <FaultString>Download failure</FaultString>
    </FaultStruct>
    <StartTime>2018-08-10T14:27:17+02:00</StartTime>
    <CompleteTime>2018-08-10T14:27:17+02:00</CompleteTime>
   </cwmp:TransferComplete>
  </soap_env:Body>
 </soap_env:Envelope>


# RESPONSE Fri Aug 10 2018 14:27:19 GMT+0200 (CEST)
{"Server":"GenieACS/1.1.1","SOAPServer":"GenieACS/1.1.1","Content-Type":"text/xml; charset=\"utf-8\""}
<?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-2"><soap-env:Header><cwmp:ID soap-env:mustUnderstand="1">3</cwmp:ID></soap-env:Header><soap-env:Body><cwmp:TransferCompleteResponse/></soap-env:Body></soap-env:Envelope>


# REQUEST Fri Aug 10 2018 14:27:19 GMT+0200 (CEST)
{"host":"host","connection":"close","content-length":"0","cookie":"session=672c8647267e015c","user-agent":"easycwmp","content-type":"text/xml; charset=\"utf-8\""}


# RESPONSE Fri Aug 10 2018 14:27:19 GMT+0200 (CEST)
{"Server":"GenieACS/1.1.1","SOAPServer":"GenieACS/1.1.1","Content-Type":"text/xml; charset=\"utf-8\""}
<?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-2"><soap-env:Header><cwmp:ID soap-env:mustUnderstand="1">16523ce2d060000</cwmp:ID></soap-env:Header><soap-env:Body><cwmp:Download><CommandKey>16523ce2d060000</CommandKey><FileType>12 Other File</FileType><URL>https://host:7567/test</URL><Username/><Password/><FileSize>14</FileSize><TargetFileName/><DelaySeconds>0</DelaySeconds><SuccessURL/><FailureURL/></cwmp:Download></soap-env:Body></soap-env:Envelope>


# REQUEST Fri Aug 10 2018 14:27:19 GMT+0200 (CEST)
{"host":"host","connection":"close","content-length":"678","cookie":"session=672c8647267e015c","user-agent":"easycwmp","content-type":"text/xml; charset=\"utf-8\"","soapaction":""}
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
 <soap_env:Envelope
xmlns:soap_env="http://schemas.xmlsoap.org/soap/envelope/"
xmlns:soap_enc="http://schemas.xmlsoap.org/soap/encoding/"
xmlns:xsd="http://www.w3.org/2001/XMLSchema"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:cwmp="urn:dslforum-org:cwmp-1-2">
  <soap_env:Header>
   <cwmp:ID soap_env:mustUnderstand="1">16523ce2d060000</cwmp:ID>
  </soap_env:Header>
  <soap_env:Body>
   <cwmp:DownloadResponse>
    <Status>1</Status>
    <StartTime>0001-01-01T00:00:00Z</StartTime>
    <CompleteTime>0001-01-01T00:00:00Z</CompleteTime>
   </cwmp:DownloadResponse>
  </soap_env:Body>
 </soap_env:Envelope>


# RESPONSE Fri Aug 10 2018 14:27:19 GMT+0200 (CEST)
{"Server":"GenieACS/1.1.1","SOAPServer":"GenieACS/1.1.1","Content-Type":"text/xml; charset=\"utf-8\""}
<?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-2"><soap-env:Header><cwmp:ID soap-env:mustUnderstand="1">16523ce2d060100</cwmp:ID></soap-env:Header><soap-env:Body><cwmp:Download><CommandKey>16523ce2d060100</CommandKey><FileType>11 Shell Script</FileType><URL>https://host:7567/test_1533903958.1886573.sh</URL><Username/><Password/><FileSize>0</FileSize><TargetFileName/><DelaySeconds>0</DelaySeconds><SuccessURL/><FailureURL/></cwmp:Download></soap-env:Body></soap-env:Envelope>


acs.log (21,647 bytes)   

mohamed.kallel

2018-08-15 11:01

administrator   ~0000902

Last edited: 2018-08-15 11:02

I checked the easycwmp.log.
The easycwmp is sending the download response for each download request:



Fri Aug 10 14:26:57 2018 daemon.notice easycwmpd: received Download method from the ACS
Fri Aug 10 14:26:57 2018 daemon.notice easycwmpd: add download: delay = 0 sec, url = https://host:7567/test, FileType = '12 Other File', CommandKey = '16523cdd9bd0000'
Fri Aug 10 14:26:57 2018 daemon.notice easycwmpd: send DownloadResponse to the ACS
Fri Aug 10 14:26:58 2018 daemon.notice easycwmpd: received Download method from the ACS
Fri Aug 10 14:26:58 2018 daemon.notice easycwmpd: add download: delay = 0 sec, url = https://host:7567/test_1533903958.1886573.sh, FileType = '11 Shell Script', CommandKey = '16523cdd9bd0100'
Fri Aug 10 14:26:58 2018 daemon.notice easycwmpd: send DownloadResponse to the ACS

okraits

2018-08-27 11:05

reporter   ~0000903

Well, it says so in the log but if you look at the SOAP XML log in acs.log you see that easycwmp actually doesn't send a DownloadResponse for the second download request (although it sends one for the first download request) but already a Download Event in the next inform without having confirmed the second download request.

mohamed.kallel

2018-08-27 11:52

administrator   ~0000904

do you have pcap file?

okraits

2018-08-28 14:20

reporter  

dump.pcap (70,462 bytes)

okraits

2018-08-28 14:20

reporter   ~0000906

Please see attached file dump.pcap.

okraits

2018-09-03 15:34

reporter   ~0000909

Any news on this one?

okraits

2018-10-01 09:01

reporter   ~0000919

Could you please have a look at this issue? I would greatly appreciate it.

Issue History

Date Modified Username Field Change
2018-08-10 15:02 okraits New Issue
2018-08-10 15:02 okraits File Added: easycwmp.log
2018-08-10 15:02 okraits File Added: acs.log
2018-08-15 11:01 mohamed.kallel Note Added: 0000902
2018-08-15 11:02 mohamed.kallel Note Edited: 0000902
2018-08-27 11:05 okraits Note Added: 0000903
2018-08-27 11:52 mohamed.kallel Note Added: 0000904
2018-08-28 14:20 okraits File Added: dump.pcap
2018-08-28 14:20 okraits Note Added: 0000906
2018-09-03 15:34 okraits Note Added: 0000909
2018-10-01 09:01 okraits Note Added: 0000919