TR Log

来源：互联网发布：linux ftp服务器配置编辑：程序博客网时间：2024/05/16 11:42

------------------------------------------------------------------------------
Test cdrouter-443: OD-128 Test 9 Part 3: GetParameterNames - Partial Path - Next Level False
Module: od128.tcl
Name: od128_test_9.3
Description:

7.5.3.1 Purpose

This test validates the ability of the ACS to retrieve information about the CPE's data
hierarchy at all levels using the GetParameterNames RPC.

7.5.3.2 Procedure

1. Initiate a transaction session between the ACS and CPE through a successful
Inform exchange.

2. The ACS issues a GetParameterNames RPC specifying the following partial path
and with the NextLevel Boolean argument set to False.

IGD
InternetGatewayDevice.Layer3Forwarding.

VoIP
InternetGatewayDevice.Services.VoiceService.1.VoiceProfile.1.SIP.

STB
InternetGatewayDevice.Services.STBService.1.Capabilities.VideoDecoder.

3. The CPE issues a GetParameterNamesResponse message containing the full path
name of all parameters whose name begins with the string specified in the request.

7.5.3.3 Success Metric

      1. The CPE is able to communicate its data hierarchy at all levels below the
         specified partial path.
      2. The ACS is able to learn about the data hierarchy at all levels below the specified
         partial path.

Reference:
OD-128 Rev 3 Interoperability Test Plan for TR-069 Plugfests

------------------------------------------------------------------------------
INFO(cdrouter-443): 15:17:45| Starting test od128_test_9.3 (443)
INFO(cdrouter-443): 15:17:45| The default device type for this CPE is 'IGD'
INFO(cdrouter-443): 15:17:45| Starting GetParameterNames using partial path InternetGatewayDevice.Layer3Forwarding. and NextLevel = false
INFO(acs): 15:17:45| Starting TR-069 GetParameterNames method
INFO(acs): 15:17:45| No current ACS session exists with device, requesting connection from CPE
INFO(acs): 15:17:45| Setting default ConnectionRequestURL to http://192.168.200.2:4567/
INFO(acs): 15:17:45| Initiating attempt 1 HTTP GET with Connection: keep-alive header
INFO(acs): 15:17:45| Sending IPv4 HTTP GET for URL http://192.168.200.2:4567/
INFO(acs): 15:17:45| Opening new TCP session 192.168.20.223:11270 -> 192.168.200.2:4567
INFO(acs): 15:17:45| Sending TCP +Syn, entering state 'syn-sent', seq 0xb24dc931, ack 0x00000000
O>>>(wan-1): 15:17:45|       192.168.20.223                          192.168.200.2                           TCP       11270 > 4567 +Syn (Len=0, window=0800)
I<<<(wan-2): 15:17:45|       192.168.200.2                           192.168.20.223                          TCP       4567 > 11270 +Syn+Ack (Len=0, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:11270 received +Syn+Ack from 192.168.200.2:4567, seq 0x6df19978, ack 0xb24dc932
INFO(acs): 15:17:45| Found TCP session at port 11270 state 'syn-sent'
INFO(acs): 15:17:45| Received TCP MSS size 1450
INFO(acs): 15:17:45| Sending TCP +Ack, entering state 'established', seq 0xb24dc932, ack 0x6df19979
O>>>(wan-3): 15:17:45|       192.168.20.223                          192.168.200.2                           TCP       11270 > 4567 +Ack (Len=0, window=0800)
INFO(acs): 15:17:45| Displaying outgoing HTTP GET:

GET / HTTP/1.1
Connection: keep-alive
User-Agent: pktsrc
Host: 192.168.200.2:4567

INFO(acs): 15:17:45| Send TCP data segment with length 88, peer TCP window size is 5800 bytes
INFO(acs): 15:17:45| Sending TCP +Ack+Push, current state 'established', seq 0xb24dc932 ack 0x6df19979
O>>>(wan-4): 15:17:45|       192.168.20.223                          192.168.200.2                           TCP       11270 > 4567 +Ack+Push (Len=88, window=0800)
I<<<(wan-5): 15:17:45|       192.168.200.2                           192.168.20.223                          TCP       4567 > 11270 +Ack (Len=0, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:11270 received +Ack from 192.168.200.2:4567, seq 0x6df19979, ack 0xb24dc98a
INFO(acs): 15:17:45| Found TCP session at port 11270 state 'established'
INFO(acs): 15:17:45| TCP received 0 bytes in TCP ack
I<<<(wan-6): 15:17:45|       192.168.200.2                           192.168.20.223                          TCP       4567 > 11270 +Ack+Push (Len=228, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:11270 received +Ack+Push from 192.168.200.2:4567, seq 0x6df19979, ack 0xb24dc98a
INFO(acs): 15:17:45| Found TCP session at port 11270 state 'established'
INFO(acs): 15:17:45| TCP received 228 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xb24dc98a, ack 0x6df19a5d
O>>>(wan-7): 15:17:45|       192.168.20.223                          192.168.200.2                           TCP       11270 > 4567 +Ack (Len=0, window=0800)
INFO(acs): 15:17:45| Received 228 bytes from HTTP connection from 192.168.200.2:4567
INFO(acs): 15:17:45| Displaying HTTP GET Response:

HTTP/1.1 401 Unauthorized
Content-Length: 0
WWW-Authenticate: Digest realm="IgdAuthentication", domain="/", nonce="ZWExODZmMjQ6YjE4YTMzMDg6IDI5NDBlYTg=", qop="auth", algorithm=MD5, opaque="5ccc09c403ebaf9f0171e9517f40e41"

INFO(acs): 15:17:45| Did not find Connection header
INFO(acs): 15:17:45| Received HTTP response code 401 from http://192.168.200.2:4567/
INFO(acs): 15:17:45| Connection request to http://192.168.200.2:4567/ received response 401
INFO(acs): 15:17:45| Received request for Digest authentication
INFO(acs): 15:17:45| Found digest algorithm 'MD5', using 'MD5'
INFO(acs): 15:17:45| Digest is using the qop=auth option
INFO(acs): 15:17:45| Running http-digest nonce=ZWExODZmMjQ6YjE4YTMzMDg6IDI5NDBlYTg= cnonce=ba6841aef894092f user=qacafe realm=IgdAuthentication password=qacafe123 alg=MD5 noncecount=00000001 method=GET qop=auth uri=/
INFO(acs): 15:17:45| http-digest response is 9d3217bc1909d758c33db9513e0d82a5
INFO(acs): 15:17:45| Sending IPv4 HTTP GET for URL http://192.168.200.2:4567/
INFO(acs): 15:17:45| TCP connection for HTTP request is still open
INFO(acs): 15:17:45| Displaying outgoing HTTP GET:

GET / HTTP/1.1
Connection: keep-alive
User-Agent: pktsrc
Host: 192.168.200.2:4567
Authorization: Digest username="qacafe", realm="IgdAuthentication", nonce="ZWExODZmMjQ6YjE4YTMzMDg6IDI5NDBlYTg=", uri="/", cnonce="ba6841aef894092f", nc=00000001, qop="auth", response="9d3217bc1909d758c33db9513e0d82a5", algorithm="MD5",opaque="5ccc09c403ebaf9f0171e9517f40e41"

INFO(acs): 15:17:45| Send TCP data segment with length 366, peer TCP window size is 5800 bytes
INFO(acs): 15:17:45| Sending TCP +Ack+Push, current state 'established', seq 0xb24dc98a ack 0x6df19a5d
O>>>(wan-8): 15:17:45|       192.168.20.223                          192.168.200.2                           TCP       11270 > 4567 +Ack+Push (Len=366, window=0800)
I<<<(wan-9): 15:17:45|       192.168.200.2                           192.168.20.223                          TCP       4567 > 11270 +Ack+Push (Len=38, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:11270 received +Ack+Push from 192.168.200.2:4567, seq 0x6df19a5d, ack 0xb24dcaf8
INFO(acs): 15:17:45| Found TCP session at port 11270 state 'established'
INFO(acs): 15:17:45| TCP received 38 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xb24dcaf8, ack 0x6df19a83
O>>>(wan-10): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       11270 > 4567 +Ack (Len=0, window=0800)
I<<<(wan-11): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Syn (Len=0, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Syn from 192.168.200.2:38293, seq 0x6d90354e, ack 0x00000000
INFO(acs): 15:17:45| Accepting TCP connection from 192.168.200.2:38293
INFO(acs): 15:17:45| Received TCP MSS size 1450
INFO(acs): 15:17:45| Sending TCP +Syn+Ack, entering state 'syn-rcvd', seq 0xc874d5d4, ack 0x6d90354f
O>>>(wan-12): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Syn+Ack (Len=0, window=0800)
INFO(acs): 15:17:45| Received 38 bytes from HTTP connection from 192.168.200.2:4567
INFO(acs): 15:17:45| Displaying HTTP GET Response:

HTTP/1.1 200 OK
Content-Length: 0

INFO(acs): 15:17:45| Did not find Connection header
INFO(acs): 15:17:45| Received HTTP response code 200 from http://192.168.200.2:4567/
INFO(acs): 15:17:45| Sending TCP +Ack+Fin, entering state 'fin-wait-1', seq 0xb24dcaf8, ack 0x6df19a83
O>>>(wan-13): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       11270 > 4567 +Ack+Fin (Len=0, window=0800)
INFO(acs): 15:17:45| HTTP get with authentication received 200
INFO(acs): 15:17:45| Waiting up to 120 seconds for TR-069 RPC Method Inform
I<<<(wan-14): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       4567 > 11270 +Ack+Fin (Len=0, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:11270 received +Ack+Fin from 192.168.200.2:4567, seq 0x6df19a83, ack 0xb24dcaf8
INFO(acs): 15:17:45| Found TCP session at port 11270 state 'fin-wait-1'
INFO(acs): 15:17:45| Sending TCP +Ack, entering state 'closed', seq 0xb24dcaf9, ack 0x6df19a84
O>>>(wan-15): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       11270 > 4567 +Ack (Len=0, window=0800)
I<<<(wan-16): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack (Len=0, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack from 192.168.200.2:38293, seq 0x6d90354f, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'syn-rcvd'
INFO(acs): 15:17:45| TCP received 0 bytes in TCP-Ack
INFO(acs): 15:17:45| Entering 'established' state with connection 192.168.200.2:38293
I<<<(wan-17): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       4567 > 11270 +Ack (Len=0, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:11270 received +Ack from 192.168.200.2:4567, seq 0x6df19a84, ack 0xb24dcaf9
INFO(acs): 15:17:45| Found TCP session at port 11270 state 'closed'
I<<<(wan-18): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=17, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d90354f, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 17 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d903560
O>>>(wan-19): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-20): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=657, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d903560, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 657 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d9037f1
O>>>(wan-21): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-22): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=203, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d9037f1, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 203 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d9038bc
O>>>(wan-23): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-24): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=470, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d9038bc, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 470 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d903a92
O>>>(wan-25): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-26): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=168, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d903a92, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 168 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d903b3a
O>>>(wan-27): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-28): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=196, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d903b3a, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 196 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d903bfe
O>>>(wan-29): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-30): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=317, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d903bfe, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 317 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d903d3b
O>>>(wan-31): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-32): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=423, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d903d3b, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 423 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d903ee2
O>>>(wan-33): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-34): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=167, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d903ee2, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 167 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d903f89
O>>>(wan-35): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-36): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=271, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d903f89, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 271 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d904098
O>>>(wan-37): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-38): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=200, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904098, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 200 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d904160
O>>>(wan-39): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-40): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=229, window=16a8)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904160, ack 0xc874d5d5
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 229 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d5d5, ack 0x6d904245
O>>>(wan-41): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
INFO(acs): 15:17:45| ACS received incoming HTTP POST from 192.168.200.2:38293
INFO(acs): 15:17:45| Displaying incoming TR-069 message from 192.168.200.2:38293
INFO(acs): 15:17:45|

POST / HTTP/1.1
Host: 192.168.20.223:1234
User-Agent: BCM_TR69_CPE_04_00
Connection: keep-alive
SOAPAction:
Content-Type: text/xml
Content-Length: 3156

<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-0">
    <SOAP-ENV:Header>
      <cwmp:ID SOAP-ENV:mustUnderstand="1">412529045</cwmp:ID>
    </SOAP-ENV:Header>
    <SOAP-ENV:Body>
      <cwmp:Inform>
        <DeviceId>
          <Manufacturer>Actiontec</Manufacturer>
          <OUI>00247B</OUI>
          <ProductClass>V2000H</ProductClass>
          <SerialNumber>001505fa67d0</SerialNumber>
        </DeviceId>
        <Event SOAP-ENC:arrayType="cwmp:EventStruct[1]">
          <EventStruct>
            <EventCode>6 CONNECTION REQUEST</EventCode>
            <CommandKey></CommandKey>
          </EventStruct>
        </Event>
        <MaxEnvelopes>1</MaxEnvelopes>
        <CurrentTime>1970-01-01T00:01:57+00:00</CurrentTime>
        <RetryCount>0</RetryCount>
        <ParameterList SOAP-ENC:arrayType="cwmp:ParameterValueStruct[0008]">
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.DeviceSummary</Name>
              <Value xsi:type="xsd:string">InternetGatewayDevice:1.1[](Baseline:1, EthernetLAN:1, USBLAN:1, WiFiLAN:1, ADSLWAN:1, Time:1, IPPing:1, ATMLoopback:1, DSLDiagnostics:1, DeviceAssociation:1, SelfTestDiag:1, SimpleFirewall:1, User:1, PeriodicStatsBase:1, PeriodicStatsAdv:1)</Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.DeviceInfo.SpecVersion</Name>
              <Value xsi:type="xsd:string">1.0</Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.DeviceInfo.HardwareVersion</Name>
              <Value xsi:type="xsd:string">tmp_hardware1.0</Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.DeviceInfo.SoftwareVersion</Name>
              <Value xsi:type="xsd:string">61.40L.02</Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.DeviceInfo.ProvisioningCode</Name>
              <Value xsi:type="xsd:string"></Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.ManagementServer.ConnectionRequestURL</Name>
              <Value xsi:type="xsd:string">http://192.168.200.2:4567/</Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.ManagementServer.ParameterKey</Name>
              <Value xsi:type="xsd:string"></Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.WANDevice.3.WANConnectionDevice.1.WANPPPConnection.2.ExternalIPAddress</Name>
              <Value xsi:type="xsd:string">192.168.200.2</Value>
            </ParameterValueStruct>
        </ParameterList>
      </cwmp:Inform>
    </SOAP-ENV:Body>
</SOAP-ENV:Envelope>

INFO(acs): 15:17:45| Client connection missing authentication
INFO(acs): 15:17:45| Generated new nonce 923c5d2b0705a6ea
INFO(acs): 15:17:45| Displaying outgoing TR-069 message:

HTTP/1.1 401 Authorization Required
Content-Length: 0
WWW-Authenticate: Digest realm="qacafe", nonce="923c5d2b0705a6ea", qop="auth"

INFO(acs): 15:17:45| Send TCP data segment with length 137, peer TCP window size is 5800 bytes
INFO(acs): 15:17:45| Sending TCP +Ack+Push, current state 'established', seq 0xc874d5d5 ack 0x6d904245
O>>>(wan-42): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack+Push (Len=137, window=0800)
I<<<(wan-43): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack (Len=0, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack from 192.168.200.2:38293, seq 0x6d904245, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 0 bytes in TCP ack
I<<<(wan-44): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=17, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904245, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 17 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904256
O>>>(wan-45): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-46): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=285, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904256, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 285 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904373
O>>>(wan-47): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-48): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=255, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904373, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 255 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904472
O>>>(wan-49): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-50): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=356, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904472, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 356 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d9045d6
O>>>(wan-51): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-52): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=426, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d9045d6, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 426 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904780
O>>>(wan-53): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-54): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=216, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904780, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 216 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904858
O>>>(wan-55): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-56): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=184, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904858, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 184 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904910
O>>>(wan-57): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-58): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=139, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904910, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 139 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d90499b
O>>>(wan-59): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-60): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=386, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d90499b, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 386 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904b1d
O>>>(wan-61): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-62): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=235, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904b1d, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 235 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904c08
O>>>(wan-63): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-64): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=199, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904c08, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 199 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904ccf
O>>>(wan-65): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-66): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=169, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904ccf, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 169 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904d78
O>>>(wan-67): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-68): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=424, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904d78, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 424 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904f20
O>>>(wan-69): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-70): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=126, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904f20, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 126 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904f9e
O>>>(wan-71): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-72): 15:17:45|      00:15:05:fa:67:d0                       00:0b:0b:00:00:01                       PPP/LCP   Echo-Request (ID=3)
INFO(wan): 15:17:45| Received LCP Echo-Request (id 3)
INFO(wan): 15:17:45| Sending LCP Echo-Reply (id 3)
O>>>(wan-73): 15:17:45|      00:0b:0b:00:00:01                       00:15:05:fa:67:d0                       PPP/LCP   Echo-Reply (ID=3)
I<<<(wan-74): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=1, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904f9e, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 1 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d904f9f
O>>>(wan-75): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-76): 15:17:45|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=102, window=1920)
INFO(acs): 15:17:45| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d904f9f, ack 0xc874d65e
INFO(acs): 15:17:45| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:45| TCP received 102 bytes in TCP ack
INFO(acs): 15:17:45| Sending TCP +Ack, current state 'established', seq 0xc874d65e, ack 0x6d905005
O>>>(wan-77): 15:17:45|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
INFO(acs): 15:17:45| ACS received incoming HTTP POST from 192.168.200.2:38293
INFO(acs): 15:17:45| Displaying incoming TR-069 message from 192.168.200.2:38293
INFO(acs): 15:17:45|

POST / HTTP/1.1
Host: 192.168.20.223:1234
User-Agent: BCM_TR69_CPE_04_00
Connection: keep-alive
Authorization: Digest username="qacafe", realm="qacafe", algorithm="MD5", qop="auth", uri="/", nonce="923c5d2b0705a6ea", cnonce="MDAwMTE3AA==", nc=00000001, response="c52f26ee167d1f51b9e9d6ff11339f54"
SOAPAction:
Content-Type: text/xml
Content-Length: 3156

<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-0">
    <SOAP-ENV:Header>
      <cwmp:ID SOAP-ENV:mustUnderstand="1">176797496</cwmp:ID>
    </SOAP-ENV:Header>
    <SOAP-ENV:Body>
      <cwmp:Inform>
        <DeviceId>
          <Manufacturer>Actiontec</Manufacturer>
          <OUI>00247B</OUI>
          <ProductClass>V2000H</ProductClass>
          <SerialNumber>001505fa67d0</SerialNumber>
        </DeviceId>
        <Event SOAP-ENC:arrayType="cwmp:EventStruct[1]">
          <EventStruct>
            <EventCode>6 CONNECTION REQUEST</EventCode>
            <CommandKey></CommandKey>
          </EventStruct>
        </Event>
        <MaxEnvelopes>1</MaxEnvelopes>
        <CurrentTime>1970-01-01T00:01:57+00:00</CurrentTime>
        <RetryCount>0</RetryCount>
        <ParameterList SOAP-ENC:arrayType="cwmp:ParameterValueStruct[0008]">
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.DeviceSummary</Name>
              <Value xsi:type="xsd:string">InternetGatewayDevice:1.1[](Baseline:1, EthernetLAN:1, USBLAN:1, WiFiLAN:1, ADSLWAN:1, Time:1, IPPing:1, ATMLoopback:1, DSLDiagnostics:1, DeviceAssociation:1, SelfTestDiag:1, SimpleFirewall:1, User:1, PeriodicStatsBase:1, PeriodicStatsAdv:1)</Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.DeviceInfo.SpecVersion</Name>
              <Value xsi:type="xsd:string">1.0</Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.DeviceInfo.HardwareVersion</Name>
              <Value xsi:type="xsd:string">tmp_hardware1.0</Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.DeviceInfo.SoftwareVersion</Name>
              <Value xsi:type="xsd:string">61.40L.02</Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.DeviceInfo.ProvisioningCode</Name>
              <Value xsi:type="xsd:string"></Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.ManagementServer.ConnectionRequestURL</Name>
              <Value xsi:type="xsd:string">http://192.168.200.2:4567/</Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.ManagementServer.ParameterKey</Name>
              <Value xsi:type="xsd:string"></Value>
            </ParameterValueStruct>
            <ParameterValueStruct>
              <Name>InternetGatewayDevice.WANDevice.3.WANConnectionDevice.1.WANPPPConnection.2.ExternalIPAddress</Name>
              <Value xsi:type="xsd:string">192.168.200.2</Value>
            </ParameterValueStruct>
        </ParameterList>
      </cwmp:Inform>
    </SOAP-ENV:Body>
</SOAP-ENV:Envelope>

INFO(acs): 15:17:45| Running http-digest nonce=923c5d2b0705a6ea cnonce=MDAwMTE3AA== user=qacafe realm=qacafe password=qacafe123 alg=MD5 noncecount=00000001 method=POST qop=auth uri=/
INFO(acs): 15:17:45| http-digest response is c52f26ee167d1f51b9e9d6ff11339f54
INFO(acs): 15:17:45| Authorization is successful for user 'qacafe'
INFO(acs): 15:17:45| Authentication succeeded for 192.168.200.2:38293
INFO(acs): 15:17:46| Received Inform RPC from 192.168.200.2
INFO(acs): 15:17:46| Received Inform from known device Actiontec, Serial Number 001505fa67d0
INFO(acs): 15:17:46| Received event code '6 CONNECTION REQUEST'
INFO(acs): 15:17:46| Starting new ACS session with CPE device 00247B-001505fa67d0
INFO(acs): 15:17:46| Preparing InformResponse
INFO(acs): 15:17:46| Adding Soap:ID to InformResponse reply.
INFO(acs): 15:17:46| Queuing new RPC for 00247B-001505fa67d0
INFO(acs): 15:17:46| Saved 8 Name/Value pairs for 00247B-001505fa67d0
INFO(acs): 15:17:46| ConnectionRequestURL is http://192.168.200.2:4567/
INFO(acs): 15:17:46| ACS is setting cookie 'session="00247B-001505fa67d0-13"'
INFO(acs): 15:17:46| Serializing XML to send
INFO(acs): 15:17:46| Sending ACS response HTTP/1.1 200 OK to 192.168.200.2:38293
INFO(acs): 15:17:46| Displaying outgoing TR-069 message:

HTTP/1.1 200 OK
Set-Cookie2: session="00247B-001505fa67d0-13"; Version="1"; Discard; Path="/"
Content-Type: text/xml
Content-Length: 536

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

INFO(acs): 15:17:46| Send TCP data segment with length 679, peer TCP window size is 6432 bytes
INFO(acs): 15:17:46| Sending TCP +Ack+Push, current state 'established', seq 0xc874d65e ack 0x6d905005
O>>>(wan-78): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack+Push (Len=679, window=0800)
INFO(acs): 15:17:46| TCP connection is in state established
INFO(acs): 15:17:46| TCP connection is in state established
INFO(acs): 15:17:46| Found existing TR-069 session with 00247B-001505fa67d0
INFO(acs): 15:17:46| Queuing new RPC for 00247B-001505fa67d0
INFO(acs): 15:17:46| Adding GetParameterNames RPC to list of SOAP envelopes to send
INFO(acs): 15:17:46| Waiting up to 180 seconds for TR-069 RPC Method GetParameterNamesResponse
I<<<(wan-79): 15:17:46|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=17, window=1fd4)
INFO(acs): 15:17:46| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d905005, ack 0xc874d905
INFO(acs): 15:17:46| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:46| TCP received 17 bytes in TCP ack
INFO(acs): 15:17:46| Sending TCP +Ack, current state 'established', seq 0xc874d905, ack 0x6d905016
O>>>(wan-80): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-81): 15:17:46|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=386, window=1fd4)
INFO(acs): 15:17:46| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d905016, ack 0xc874d905
INFO(acs): 15:17:46| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:46| TCP received 386 bytes in TCP ack
INFO(acs): 15:17:46| Sending TCP +Ack, current state 'established', seq 0xc874d905, ack 0x6d905198
O>>>(wan-82): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
INFO(acs): 15:17:46| ACS received incoming HTTP POST from 192.168.200.2:38293
INFO(acs): 15:17:46| Displaying incoming TR-069 message from 192.168.200.2:38293
INFO(acs): 15:17:46|

POST / HTTP/1.1
Host: 192.168.20.223:1234
User-Agent: BCM_TR69_CPE_04_00
Connection: keep-alive
Authorization: Digest username="qacafe", realm="qacafe", algorithm="MD5", qop="auth", uri="/", nonce="923c5d2b0705a6ea", cnonce="MDAwMTE3AA==", nc=00000002, response="3d0462e5b71811fcabdb8bbc6fea3466"
SOAPAction:
Cookie: session="00247B-001505fa67d0-13"
Content-Type: text/xml
Content-Length: 0

INFO(acs): 15:17:46| Running http-digest nonce=923c5d2b0705a6ea cnonce=MDAwMTE3AA== user=qacafe realm=qacafe password=qacafe123 alg=MD5 noncecount=00000002 method=POST qop=auth uri=/
INFO(acs): 15:17:46| http-digest response is 3d0462e5b71811fcabdb8bbc6fea3466
INFO(acs): 15:17:46| Authorization is successful for user 'qacafe'
INFO(acs): 15:17:46| ACS found client Cookie session="00247B-001505fa67d0-13"
INFO(acs): 15:17:46| Cookie maps to deviceId 00247B-001505fa67d0
INFO(acs): 15:17:46| Authentication succeeded for 192.168.200.2:38293
INFO(acs): 15:17:46| ACS is setting cookie 'session="00247B-001505fa67d0-13"'
INFO(acs): 15:17:46| Serializing XML to send
INFO(acs): 15:17:46| Sending ACS response HTTP/1.1 200 OK to 192.168.200.2:38293
INFO(acs): 15:17:46| Displaying outgoing TR-069 message:

HTTP/1.1 200 OK
Set-Cookie2: session="00247B-001505fa67d0-13"; Version="1"; Discard; Path="/"
Content-Type: text/xml
Content-Length: 610

<SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" xmlns:SOAP-ENC="http://schemas.xmlsoap.org/soap/encoding/" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:cwmp="urn:dslforum-org:cwmp-1-0">
<SOAP-ENV:Header>
    <cwmp:ID SOAP-ENV:mustUnderstand="1">5</cwmp:ID>
</SOAP-ENV:Header>
<SOAP-ENV:Body>
    <cwmp:GetParameterNames>
      <ParameterPath>InternetGatewayDevice.Layer3Forwarding.</ParameterPath>
      <NextLevel>false</NextLevel>
    </cwmp:GetParameterNames>
</SOAP-ENV:Body>
</SOAP-ENV:Envelope>

INFO(acs): 15:17:46| Send TCP data segment with length 753, peer TCP window size is 8148 bytes
INFO(acs): 15:17:46| Sending TCP +Ack+Push, current state 'established', seq 0xc874d905 ack 0x6d905198
O>>>(wan-83): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack+Push (Len=753, window=0800)
I<<<(wan-84): 15:17:46|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=17, window=234c)
INFO(acs): 15:17:46| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d905198, ack 0xc874dbf6
INFO(acs): 15:17:46| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:46| TCP received 17 bytes in TCP ack
INFO(acs): 15:17:46| Sending TCP +Ack, current state 'established', seq 0xc874dbf6, ack 0x6d9051a9
O>>>(wan-85): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-86): 15:17:46|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=299, window=234c)
INFO(acs): 15:17:46| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d9051a9, ack 0xc874dbf6
INFO(acs): 15:17:46| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:46| TCP received 299 bytes in TCP ack
INFO(acs): 15:17:46| Sending TCP +Ack, current state 'established', seq 0xc874dbf6, ack 0x6d9052d4
O>>>(wan-87): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-88): 15:17:46|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=384, window=234c)
INFO(acs): 15:17:46| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d9052d4, ack 0xc874dbf6
INFO(acs): 15:17:46| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:46| TCP received 384 bytes in TCP ack
INFO(acs): 15:17:46| Sending TCP +Ack, current state 'established', seq 0xc874dbf6, ack 0x6d905454
O>>>(wan-89): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-90): 15:17:46|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=369, window=234c)
INFO(acs): 15:17:46| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d905454, ack 0xc874dbf6
INFO(acs): 15:17:46| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:46| TCP received 369 bytes in TCP ack
INFO(acs): 15:17:46| Sending TCP +Ack, current state 'established', seq 0xc874dbf6, ack 0x6d9055c5
O>>>(wan-91): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
I<<<(wan-92): 15:17:46|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Push (Len=516, window=234c)
INFO(acs): 15:17:46| 192.168.20.223:1234 received +Ack+Push from 192.168.200.2:38293, seq 0x6d9055c5, ack 0xc874dbf6
INFO(acs): 15:17:46| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:46| TCP received 516 bytes in TCP ack
INFO(acs): 15:17:46| Sending TCP +Ack, current state 'established', seq 0xc874dbf6, ack 0x6d9057c9
O>>>(wan-93): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack (Len=0, window=0800)
INFO(acs): 15:17:46| ACS received incoming HTTP POST from 192.168.200.2:38293
INFO(acs): 15:17:46| Displaying incoming TR-069 message from 192.168.200.2:38293
INFO(acs): 15:17:46|

POST / HTTP/1.1
Host: 192.168.20.223:1234
User-Agent: BCM_TR69_CPE_04_00
Connection: keep-alive
Authorization: Digest username="qacafe", realm="qacafe", algorithm="MD5", qop="auth", uri="/", nonce="923c5d2b0705a6ea", cnonce="MDAwMTE3AA==", nc=00000003, response="66ae6cfb48b6f2fabde7de073e10e2af"
SOAPAction:
Cookie: session="00247B-001505fa67d0-13"
Content-Type: text/xml
Content-Length: 1179

INFO(acs): 15:17:46| Running http-digest nonce=923c5d2b0705a6ea cnonce=MDAwMTE3AA== user=qacafe realm=qacafe password=qacafe123 alg=MD5 noncecount=00000003 method=POST qop=auth uri=/
INFO(acs): 15:17:46| http-digest response is 66ae6cfb48b6f2fabde7de073e10e2af
INFO(acs): 15:17:46| Authorization is successful for user 'qacafe'
INFO(acs): 15:17:46| ACS found client Cookie session="00247B-001505fa67d0-13"
INFO(acs): 15:17:46| Cookie maps to deviceId 00247B-001505fa67d0
INFO(acs): 15:17:46| Authentication succeeded for 192.168.200.2:38293
INFO(acs): 15:17:46| Received GetParameterNamesResponse RPC from 192.168.200.2
INFO(acs): 15:17:46| ACS does not have any additional Envelopes to send
INFO(acs): 15:17:46| ACS is setting cookie 'session="00247B-001505fa67d0-13"'
INFO(acs): 15:17:46| Serializing XML to send
INFO(acs): 15:17:46| Sending empty ACS response HTTP/1.1 204 No Content to 192.168.200.2:38293
INFO(acs): 15:17:46| Displaying outgoing TR-069 message:

HTTP/1.1 204 No Content
Set-Cookie2: session="00247B-001505fa67d0-13"; Version="1"; Discard; Path="/"
Content-Length: 0

INFO(acs): 15:17:46| Send TCP data segment with length 125, peer TCP window size is 9036 bytes
INFO(acs): 15:17:46| Sending TCP +Ack+Push, current state 'established', seq 0xc874dbf6 ack 0x6d9057c9
O>>>(wan-94): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack+Push (Len=125, window=0800)
INFO(acs): 15:17:46| Received GetParameterNamesResponse from 00247B-001505fa67d0
INFO(acs): 15:17:46| Verifying arguments for RPC Method: GetParameterNamesResponse.
PASS(cdrouter-443): 15:17:46| GetParameterNames succeeded with 3 returned Names
PASS(cdrouter-443): 15:17:46| Found InternetGatewayDevice.Layer3Forwarding.DefaultConnectionService in Names list
PASS(cdrouter-443): 15:17:46| Found InternetGatewayDevice.Layer3Forwarding.ForwardNumberOfEntries in Names list
INFO(cdrouter-443): 15:17:46| Waiting for current TR-069 session to end
INFO(acs): 15:17:46| Waiting for TR-069 session to finish
INFO(acs): 15:17:46| TCP connection is in state established
INFO(acs): 15:17:46| Found active TR-069 session with 00247B-001505fa67d0
INFO(acs): 15:17:46| Waiting up to 45 seconds for empty POST from CPE
I<<<(wan-95): 15:17:46|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack (Len=0, window=234c)
INFO(acs): 15:17:46| 192.168.20.223:1234 received +Ack from 192.168.200.2:38293, seq 0x6d9057c9, ack 0xc874dc73
INFO(acs): 15:17:46| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:46| TCP received 0 bytes in TCP ack
I<<<(wan-96): 15:17:46|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack+Fin (Len=0, window=234c)
INFO(acs): 15:17:46| 192.168.20.223:1234 received +Ack+Fin from 192.168.200.2:38293, seq 0x6d9057c9, ack 0xc874dc73
INFO(acs): 15:17:46| Found TCP server session with 192.168.200.2:38293 state 'established'
INFO(acs): 15:17:46| TCP received 0 bytes in TCP ack
INFO(acs): 15:17:46| Connection closed by peer 192.168.200.2
INFO(acs): 15:17:46| Sending TCP +Ack+Fin, entering state 'last-ack', seq 0xc874dc73, ack 0x6d9057ca
O>>>(wan-97): 15:17:46|      192.168.20.223                          192.168.200.2                           TCP       1234 > 38293 +Ack+Fin (Len=0, window=0800)
INFO(acs): 15:17:46| ACS session has been closed
INFO(acs): 15:17:46| Ending ACS session with 00247B-001505fa67d0
INFO(acs): 15:17:46| Received empty POST from CPE or session closed CPE
INFO(acs): 15:17:46| ACS has 0 envelopes left to send
INFO(acs): 15:17:46| Can not find active TR-069 session, session is finished
INFO(acs): 15:17:46| ACS RPC queue is now empty
INFO(acs): 15:17:46| TR-069 session has ended
I<<<(wan-98): 15:17:46|      192.168.200.2                           192.168.20.223                          TCP       38293 > 1234 +Ack (Len=0, window=234c)
INFO(acs): 15:17:46| 192.168.20.223:1234 received +Ack from 192.168.200.2:38293, seq 0x6d9057ca, ack 0xc874dc74
INFO(acs): 15:17:46| Found TCP server session with 192.168.200.2:38293 state 'last-ack'
PASS(cdrouter-443): 15:17:49| Test od128_test_9.3 (443) passed