IPSEC/L2TP discconect after one minute

076Lucas · Fri Nov 15, 2019 11:55 pm

Hi,

I'm trying to set-up a VPN based on IpSec/L2TP. Everything works and I can use the VPN connection when connected. I see the L2TP tunnel listen under PPP ->Interfaces. But after one minute or so the L2TP tunnel drops. The IPSEC connection just stays connected. It looks like the L2TP does not get a reply on a HELO message and discconects then. See below the L2TP log where it ends. Does anyone have a clou? Tried already several things like from this topic: viewtopic.php?t=72198

Code: Select all


Nov/15/2019 22:49:50 l2tp,debug,packet L2TPDBG===>:     (M) Message-Type=HELLO

Nov/15/2019 22:49:52 l2tp,ppp,debug,packet L2TPDBG===>:  <X.X.X.X>: sent LCP EchoReq id=0x7

Nov/15/2019 22:49:52 l2tp,ppp,debug,packet L2TPDBG===>:     <magic 0xc25639d>

Nov/15/2019 22:49:52 l2tp,ppp,debug,packet L2TPDBG===>:  <X.X.X.X>: rcvd LCP EchoRep id=0x7

Nov/15/2019 22:49:52 l2tp,ppp,debug,packet L2TPDBG===>:     <magic 0x10400d01>

Nov/15/2019 22:49:54 l2tp,debug,packet L2TPDBG===>: sent control message to X.X.X.X:44758 from Y.Y.Y.Y:1701

Nov/15/2019 22:49:54 l2tp,debug,packet L2TPDBG===>:     tunnel-id=37551, session-id=0, ns=2, nr=4

Nov/15/2019 22:49:54 l2tp,debug,packet L2TPDBG===>:     (M) Message-Type=HELLO

Nov/15/2019 22:50:02 l2tp,debug,packet L2TPDBG===>: sent control message to X.X.X.X:44758 from Y.Y.Y.Y:1701

Nov/15/2019 22:50:02 l2tp,debug,packet L2TPDBG===>:     tunnel-id=37551, session-id=0, ns=2, nr=4

Nov/15/2019 22:50:02 l2tp,debug,packet L2TPDBG===>:     (M) Message-Type=HELLO

Nov/15/2019 22:50:10 l2tp,debug L2TPDBG===>: tunnel 12 received no replies, disconnecting

Nov/15/2019 22:50:10 l2tp,debug L2TPDBG===>: tunnel 12 entering state: dead

Nov/15/2019 22:50:10 l2tp,debug L2TPDBG===>: session 1 entering state: dead

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: LCP lowerdown

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: LCP closed

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: CCP lowerdown

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: BCP lowerdown

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: BCP down event in starting state

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: IPCP lowerdown

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: IPCP closed

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: IPV6CP lowerdown

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: IPV6CP down event in starting state

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: MPLSCP lowerdown

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: CCP close

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: BCP close

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: IPCP close

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: IPV6CP close

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: MPLSCP close

Nov/15/2019 22:50:10 l2tp,ppp,info L2TPDBG===>: <l2tp-User1>: terminating... - hungup

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: LCP lowerdown

Nov/15/2019 22:50:10 l2tp,ppp,debug L2TPDBG===>: <X.X.X.X>: LCP down event in starting state

Nov/15/2019 22:50:10 l2tp,ppp,info,account L2TPDBG===>: User1 logged out, 84 12694 16678 89 82

Nov/15/2019 22:50:10 l2tp,ppp,info L2TPDBG===>: <l2tp-User1>: disconnected

sindy · Sat Nov 16, 2019 2:17 pm

The symptoms resemble a default route conflict to me. If you let the /interface l2tp-client install a default route via itself when it comes up, the IPsec transport packets carrying the L2TP traffic towards the L2TP server may start getting routed using this new default route once the routing cache expires, which means that a routing loop occurs and the packets don't actually get anywhere.

So show your full configuration export. There are multiple ways how to deal with this issue, the simplest one is to set up an individual route towards the L2TP server, but it may not be that simple if the latter is identified by a domain name and its actual address changes over time or if your WAN IP configuration is assigned dynamically.

076Lucas · Mon Nov 18, 2019 9:16 pm

The symptoms resemble a default route conflict to me. If you let the /interface l2tp-client install a default route via itself when it comes up, the IPsec transport packets carrying the L2TP traffic towards the L2TP server may start getting routed using this new default route once the routing cache expires, which means that a routing loop occurs and the packets don't actually get anywhere.

So show your full configuration export. There are multiple ways how to deal with this issue, the simplest one is to set up an individual route towards the L2TP server, but it may not be that simple if the latter is identified by a domain name and its actual address changes over time or if your WAN IP configuration is assigned dynamically.

Hi Sindy,
Thanks for your reply. The config is as follows:

Code: Select all


/interface bridge

add arp=proxy-arp fast-forward=no igmp-snooping=yes name=bridge-local

add arp=proxy-arp fast-forward=no name=bridge-vlan pvid=40 vlan-filtering=yes



/interface ethernet

set [ find default-name=ether1 ] arp=proxy-arp name=ether1-gateway

set [ find default-name=ether3 ] speed=100Mbps

set [ find default-name=ether4 ] speed=100Mbps

set [ find default-name=ether5 ] speed=100Mbps

set [ find default-name=ether6 ] advertise=\

    10M-half,10M-full,100M-half,100M-full,1000M-half,1000M-full

set [ find default-name=ether7 ] advertise=\

    10M-half,10M-full,100M-half,100M-full,1000M-half,1000M-full

set [ find default-name=ether8 ] advertise=\

    10M-half,10M-full,100M-half,100M-full,1000M-half,1000M-full

set [ find default-name=ether9 ] advertise=\

    10M-half,10M-full,100M-half,100M-full,1000M-half,1000M-full

set [ find default-name=ether10 ] advertise=\

    10M-half,10M-full,100M-half,100M-full,1000M-half,1000M-full



/interface vlan

add interface=ether1-gateway name=vlan1.4 vlan-id=4

add interface=ether1-gateway name=vlan1.6 vlan-id=6

add interface=ether5 name=vlan30 vlan-id=30

add interface=bridge-vlan name=vlan40 vlan-id=1

add interface=ether5 name=vlan50 vlan-id=50

add interface=ether5 name=vlan60 vlan-id=60

add interface=ether4 name=vlan220 vlan-id=220

add interface=ether4 name=vlan221 vlan-id=221

add interface=ether4 name=vlan222 vlan-id=222

add interface=ether5 name=vlan223 vlan-id=223



/interface pppoe-client

add add-default-route=yes allow=pap,mschap2 disabled=no interface=vlan1.6 \

    keepalive-timeout=20 max-mru=1480 max-mtu=1480 name=ppoe password=**PPOE_PASSWORD** \

    user=**PPOE_USERNAME**



/ip ipsec profile

set [ find default=yes ] nat-traversal=no

/ip ipsec proposal

set [ find default=yes ] enc-algorithms=aes-256-cbc,aes-128-cbc lifetime=8h



/interface l2tp-server server

set authentication=mschap2 default-profile=profile1-L2TP_users enabled=yes \

    ipsec-secret=**PSK** keepalive-timeout=5 \

    max-mru=1460 max-mtu=1460 use-ipsec=required



/ip pool

add name=pool1-L2TP_users ranges=192.168.125.100-192.168.125.200



/ppp profile

add local-address=192.168.125.1 name=profile1-L2TP_users remote-address=\

    pool1-L2TP_users use-encryption=yes



/routing bgp instance

set default disabled=yes



/interface bridge port

add bridge=bridge-local hw=no interface=ether2

add bridge=bridge-local hw=no interface=ether3

add bridge=bridge-local hw=no interface=ether4

add bridge=bridge-local interface=ether6



/ip neighbor discovery-settings

set discover-interface-list=discover



/interface l2tp-server server

set authentication=mschap2 default-profile=profile1-L2TP_users enabled=yes \

    ipsec-secret=**PSK** keepalive-timeout=5 \

    max-mru=1460 max-mtu=1460 use-ipsec=required



/interface list member

add interface=ether2 list=discover

add interface=ether3 list=discover

add interface=ether4 list=discover

add interface=ether5 list=discover

add interface=ether6 list=discover

add interface=ether7 list=discover

add interface=ether8 list=discover

add interface=ether9 list=discover

add interface=ether10 list=discover

add interface=bridge-local list=discover

add interface=vlan1.4 list=discover

add interface=vlan30 list=discover



/ip firewall filter

add action=accept chain=input dst-port=1701 protocol=udp

add action=accept chain=input dst-port=4500 protocol=udp

add action=accept chain=input dst-port=500 protocol=udp

add action=accept chain=input protocol=ipsec-esp



/ip ipsec policy

set 0 dst-address=0.0.0.0/0 src-address=0.0.0.0/0



/ip service

set telnet disabled=yes

set ftp disabled=yes

set www disabled=yes

set ssh port=

set api disabled=yes

set api-ssl disabled=yes

/ip ssh

set strong-crypto=yes



/ip upnp

set enabled=yes show-dummy-rule=no



/ip upnp interfaces

add interface=bridge-local type=internal

add interface=pppoe type=external



/ppp secret

add name=**USERNAME** \

    password=\

    **PASSWORD** \

    profile=profile1-L2TP_users service=l2tp



/routing igmp-proxy

set quick-leave=yes



/routing igmp-proxy interface

add alternative-subnets=X.X.X.X/16,Y.Y.Y.Y/16 interface=vlan1.4 \

    threshold=0 upstream=yes

add alternative-subnets=0.0.0.0/0 interface=bridge-local

076Lucas · Mon Nov 18, 2019 9:44 pm

I'm a step further I think. I added the L2TP server but not the interface.
I added now the L2TP interface and now I'm able to create a route. But it still disconnects after a minute. But now with another message:

sindy · Mon Nov 18, 2019 9:55 pm

On the server side, adding the interface is optional, if you need to make it exist even when the user is not connected because you want to refer to it in firewall rules. I'll have a look at your configuration in an hour or so.

076Lucas · Mon Nov 18, 2019 10:31 pm

Forget my last reply, it is still the same. Also with adding that interface. SO that is indeed no resolution.

The connection dies everytime exactly after 83/84 seconds, and I'm using an Android phone. There is already a similair topic about (you replied also on this). But without solution:

viewtopic.php?t=149823

sindy · Mon Nov 18, 2019 11:10 pm

Okay. From your OP I did not understand that the Mikrotik is on the server side. In this case, the stealing of default route would be possible as well, but you have to spend much more effort to do that

And it's not your case. Just two more questions from this area, do you get a public IP from the PPPoE server? And what's the IP of the default gateway you get assigned, doesn't it fit into 192.168.0.0/16?

Now the most important thing: your current firewall rules protect nothing. The default action in each chain is accept, so after you selectively accept matching packets by their dedicated rules, the rest is accepted by default anyway. So copy-pasting the default firewall rules from 6.45.7 (obtained using system default configuration print on a SOHO grade device) here:
/ip firewall nat add chain=srcnat out-interface-list=WAN ipsec-policy=out,none action=masquerade comment="defconf: masquerade"
/ip firewall {
filter add chain=input action=accept connection-state=established,related,untracked comment="defconf: accept established,related,untracked"
filter add chain=input action=drop connection-state=invalid comment="defconf: drop invalid"
filter add chain=input action=accept protocol=icmp comment="defconf: accept ICMP"
filter add chain=input action=accept dst-address=127.0.0.1 comment="defconf: accept to local loopback (for CAPsMAN)"
#####
filter add chain=input action=drop in-interface-list=!LAN comment="defconf: drop all not coming from LAN"
filter add chain=forward action=accept ipsec-policy=in,ipsec comment="defconf: accept in ipsec policy"
filter add chain=forward action=accept ipsec-policy=out,ipsec comment="defconf: accept out ipsec policy"
filter add chain=forward action=fasttrack-connection connection-state=established,related comment="defconf: fasttrack"
filter add chain=forward action=accept connection-state=established,related,untracked comment="defconf: accept established,related, untracked"
filter add chain=forward action=drop connection-state=invalid comment="defconf: drop invalid"
filter add chain=forward action=drop connection-state=new connection-nat-state=!dstnat in-interface-list=WAN comment="defconf: drop all from WAN not DSTNATed"
}
But if the system was exposed to the internet with firewall set like this for a while, I'd recommend to netinstall it just for the case and use different passwords than ever before for all user accounts.
After netinstall, the rules from the default configuration will be there (unless you have a CCR or something like that), and you'll place the ones necessary for L2TP/IPsec instead of the ##### line above.
If you take the risk of not netinstalling it, make sure that you populate the /interface list LAN and WAN with the corresponding member interfaces, otherwise you may lock yourself out except access via MAC address (winbox & mac-telnet from another Tik), and even the access via MAC adrdress depends on what's configured in the allowed-interface-list under /tool mac-server

To your initial problem, the only things which come to my mind except a faulty client are:

a hyperactive firewall somewhere on the path between the client and your Tik server that closes the pinhole so quickly that the L2TP keepalives sent by the server don't get through (I'm not sure whether the auto-generated IPsec peer uses IPSec keepalives, these are usually sent every 20s, use /ip ipsec peer print detail to see this)
a frequently changing dynamic address assignment to the client itself or to the NAT device behind which the client is, so the packets from the server don't reach it after the change of the address

You can confirm or deny whether one of those is the case by running Wireshark on the client with a live packet list update (filtering for the IP of the server) and watching whether the IPsec transport packet comes when the server sends the HELLO (on server, you'd be running /tool sniffer quick port=4500 or /tool sniffer quick ip-protocol=ipsec-esp, depending on whether the client is behind a NAT or not, respectively.

sindy · Mon Nov 18, 2019 11:17 pm

I'm using an Android phone.

OK, that makes my suggestion to use Wireshark useless.

There is already a similair topic about (you replied also on this).

I did, but the feedback to my last post there never came. There, I was suspecting the complex way to steal the default route because @kevinsaye hasn't shown the configuration; you did, and there is no routes item in the /ppp secret, so it cannot be the explanation.

So it could be the Android version, none of my Android phones has ever shown such behaviour but that doesn't mean that some release cannot have this bug. Do you have a chance to test using another client? Is the Android connecting via mobile network or via WiFi network? And could it be that you are testing it on your home LAN (I cannot see any signs of LAN IP configuration so I suppose not but you may have filtered some information out from the export, deeming it irrelevant)?

JordanReich · Tue Nov 19, 2019 12:19 am

I am having the exact same issue to my best understanding ...
viewtopic.php?f=2&t=154014&p=761060#p761060

Just dropping this here for reference.

If I can provide anything additional from my end to help with this please let me know!

sindy · Tue Nov 19, 2019 12:36 am

If I can provide anything additional from my end to help with this please let me know!

@JordanReich, can you run the /tool sniffer command I've given above while watching the dynamically created l2tp interface in another window? I'm interested in whether the IPsec transport packet carrying the second HELLO (which remains unresponded) is ever sent anywhere at all, and if it is, whether it is sent out the same interface like the previous traffic.

JordanReich · Tue Nov 19, 2019 12:48 am

If I can provide anything additional from my end to help with this please let me know!
@JordanReich, can you run the /tool sniffer command I've given above while watching the dynamically created l2tp interface in another window? I'm interested in whether the IPsec transport packet carrying the second HELLO (which remains unresponded) is ever sent anywhere at all, and if it is, whether it is sent out the same interface like the previous traffic.

You may need to help me with exactly what output your looking to get. But I see the following for port 4500 on the IP address of the mobile phone.

 
OutToWAN                                                                                       26.611    306 <-  F0:F7:55:48:52:BF 74:4D:28:2F:4E:2C        REMOVED-PRIVATE:54294                 REMOVED-PRIVATE:4500                   ip:udp      174   1 no

In this case the phone was the source and my router was the destination.

sindy · Tue Nov 19, 2019 1:03 am

You may need to help me with exactly what output your looking to get. But I see the following for port 4500 on the IP address of the mobile phone.
Code: Select all
 
OutToWAN                                                                                       26.611    306 <-  F0:F7:55:48:52:BF 74:4D:28:2F:4E:2C        REMOVED-PRIVATE:54294                 REMOVED-PRIVATE:4500                   ip:udp      174   1 no 

If OutToWAN is the name of the interface, and it is the same like for the previous packets to&from the address of the phone, and if the last packet seen is from server to phone and no response comes back, we may safely conclude that either the packet doesn't make it to the phone or the phone doesn't respond.

If the last packet comes from the phone, something else is rotten. In that case, we need to modify the command to /tool sniffer quick ip-address=IP.of.the.phone port=4500,1701

The point is that in receiving direction, both the IPsec transport packet and the one decapsulated from it are visible, so we should see whether the phone's last response was successfully decrypted.

JordanReich · Tue Nov 19, 2019 1:17 am

Got it, I think.

I ran the following command [tool sniffer quick ip-address=PHONE.IP port=4500,1701]

Got a lot of traffic moving back and forth router side and mobile side upon initial connection. Once the connection stalled on the phone the traffic changes to this...

Yes OutToWAN is the interface in/out.

OutToWAN                                                                                      114.781   4615 <-  F0:F7:55:48:52:BF 74:4D:28:2F:4E:2C       PHONE-IP:54294                ROUTER-IP:4500                   ip:udp      158   1 no 
OutToWAN                                                                                       115.23   4616 <-  F0:F7:55:48:52:BF 74:4D:28:2F:4E:2C        PHONE-IP:54294                ROUTER-IP:4500                   ip:udp      190   1 no 
OutToWAN                                                                                       115.45   4617 <-  F0:F7:55:48:52:BF 74:4D:28:2F:4E:2C        PHONE-IP:54294                ROUTER-IP:4500                   ip:udp      190   1 no 
OutToWAN                                                                                      115.687   4618 <-  F0:F7:55:48:52:BF 74:4D:28:2F:4E:2C        PHONE-IP:54294                ROUTER-IP:4500                   ip:udp      190   1 no 
OutToWAN                                                                                      116.139   4619 <-  F0:F7:55:48:52:BF 74:4D:28:2F:4E:2C        PHONE-IP:54294                ROUTER-IP:4500                   ip:udp      190   1 no 
OutToWAN                                                                                      116.809   4620 <-  F0:F7:55:48:52:BF 74:4D:28:2F:4E:2C        PHONE-IP:54294                ROUTER-IP:4500                   ip:udp      158   1 no 
OutToWAN                                                                                       117.02   4621 <-  F0:F7:55:48:52:BF 74:4D:28:2F:4E:2C        PHONE-IP:54294                ROUTER-IP:4500                   ip:udp      190   1 no

99% of the traffic is now PHONE-IP to ROUTER-IP. Though every once and awhile the router seems to kick a response.

OutToWAN                                                                                      267.144   4819 ->  74:4D:28:2F:4E:2C F0:F7:55:48:52:BF        ROUTER-IP:4500                   PHONE-IP:54294                ip:udp       43   0 no

Hopefully this helps!

076Lucas · Tue Nov 19, 2019 10:55 am

Okay. From your OP I did not understand that the Mikrotik is on the server side. In this case, the stealing of default route would be possible as well, but you have to spend much more effort to do that And it's not your case. Just two more questions from this area, do you get a public IP from the PPPoE server? And what's the IP of the default gateway you get assigned, doesn't it fit into 192.168.0.0/16?

Now the most important thing: your current firewall rules protect nothing. The default action in each chain is accept, so after you selectively accept matching packets by their dedicated rules, the rest is accepted by default anyway. So copy-pasting the default firewall rules from 6.45.7 (obtained using system default configuration print on a SOHO grade device) here:
/ip firewall nat add chain=srcnat out-interface-list=WAN ipsec-policy=out,none action=masquerade comment="defconf: masquerade"
/ip firewall {
filter add chain=input action=accept connection-state=established,related,untracked comment="defconf: accept established,related,untracked"
filter add chain=input action=drop connection-state=invalid comment="defconf: drop invalid"
filter add chain=input action=accept protocol=icmp comment="defconf: accept ICMP"
filter add chain=input action=accept dst-address=127.0.0.1 comment="defconf: accept to local loopback (for CAPsMAN)"
#####
filter add chain=input action=drop in-interface-list=!LAN comment="defconf: drop all not coming from LAN"
filter add chain=forward action=accept ipsec-policy=in,ipsec comment="defconf: accept in ipsec policy"
filter add chain=forward action=accept ipsec-policy=out,ipsec comment="defconf: accept out ipsec policy"
filter add chain=forward action=fasttrack-connection connection-state=established,related comment="defconf: fasttrack"
filter add chain=forward action=accept connection-state=established,related,untracked comment="defconf: accept established,related, untracked"
filter add chain=forward action=drop connection-state=invalid comment="defconf: drop invalid"
filter add chain=forward action=drop connection-state=new connection-nat-state=!dstnat in-interface-list=WAN comment="defconf: drop all from WAN not DSTNATed"
}
But if the system was exposed to the internet with firewall set like this for a while, I'd recommend to netinstall it just for the case and use different passwords than ever before for all user accounts.
After netinstall, the rules from the default configuration will be there (unless you have a CCR or something like that), and you'll place the ones necessary for L2TP/IPsec instead of the ##### line above.
If you take the risk of not netinstalling it, make sure that you populate the /interface list LAN and WAN with the corresponding member interfaces, otherwise you may lock yourself out except access via MAC address (winbox & mac-telnet from another Tik), and even the access via MAC adrdress depends on what's configured in the allowed-interface-list under /tool mac-server

To your initial problem, the only things which come to my mind except a faulty client are:
a hyperactive firewall somewhere on the path between the client and your Tik server that closes the pinhole so quickly that the L2TP keepalives sent by the server don't get through (I'm not sure whether the auto-generated IPsec peer uses IPSec keepalives, these are usually sent every 20s, use /ip ipsec peer print detail to see this)

a frequently changing dynamic address assignment to the client itself or to the NAT device behind which the client is, so the packets from the server don't reach it after the change of the address
You can confirm or deny whether one of those is the case by running Wireshark on the client with a live packet list update (filtering for the IP of the server) and watching whether the IPsec transport packet comes when the server sends the HELLO (on server, you'd be running /tool sniffer quick port=4500 or /tool sniffer quick ip-protocol=ipsec-esp, depending on whether the client is behind a NAT or not, respectively.

I get a public IP from the PPPoE server. You mean the default gateway from the PPPoE server? I need to check that. Al other addresses I use internally are 192.168.XXX.0/24. I did not post all firewall rules, because I have a lot of VLAN's with firewall rules. And also some NAT rules. But placed the VPN rules right at the top, so nothing should be blocked?

I will try with other Android devices and mobile networks. I did only try mobile networks, but not WiFi (cannot connect to itself). Also I will do the suggested troubleshooting you replied and let it know.

sindy · Tue Nov 19, 2019 11:15 am

Hopefully this helps!

It's actually not the result I've expected - things must have changed since I tried last time. Now I've checked it on my setup running 6.45.7, and the packets decapsulated from IPsec are not shown by the embedded sniffer even in the receiving direction any more, which isn't helpful for diagnostics. Given that the firewall can see the decapsulated packets, I'll try to put together firewall rules copying those packets to an external sniffer later today, so I hope someone of you affected gentlemen has a Windows or Linux PC which can serve as the external sniffer.

I mean, it's hard to guess whether the many packets coming from the phone in @JordanReich's sniff result are payload ones or control ones, so the infrequent responses from the Tik may or may not be OK. I wanted you to see whether the decapsulation of L2TP packets from the IPsec ones works at all, and if it does, what's the type of the L2TP ones (control or transport).

JordanReich · Tue Nov 19, 2019 10:16 pm

Hopefully this helps!
It's actually not the result I've expected - things must have changed since I tried last time. Now I've checked it on my setup running 6.45.7, and the packets decapsulated from IPsec are not shown by the embedded sniffer even in the receiving direction any more, which isn't helpful for diagnostics. Given that the firewall can see the decapsulated packets, I'll try to put together firewall rules copying those packets to an external sniffer later today, so I hope someone of you affected gentlemen has a Windows or Linux PC which can serve as the external sniffer.

I mean, it's hard to guess whether the many packets coming from the phone in @JordanReich's sniff result are payload ones or control ones, so the infrequent responses from the Tik may or may not be OK. I wanted you to see whether the decapsulation of L2TP packets from the IPsec ones works at all, and if it does, what's the type of the L2TP ones (control or transport).

I have an accessible server farm. So we can run whatever tests you need to run. Not a problem.

sindy · Tue Nov 19, 2019 10:50 pm

I have an accessible server farm. So we can run whatever tests you need to run. Not a problem.

OK then. Assume p.p.p.p is the remote IP from (behind) which the phone establishes the L2TP/IPsec connection, and s.s.s.s is the address of the server which will do the sniffing. So place the following four rules to the very beginning of their respective chains in /ip firewall mangle:

action=sniff-tzsp chain=prerouting dst-port=500,1701,4500 protocol=udp sniff-target=s.s.s.s sniff-target-port=37008 src-address=p.p.p.p
action=sniff-tzsp chain=prerouting protocol=ipsec-esp sniff-target=s.s.s.s sniff-target-port=37008 src-address=p.p.p.p

action=sniff-tzsp chain=postrouting dst-address=p.p.p.p protocol=udp sniff-target=s.s.s.s sniff-target-port=37008 src-port=500,1701,4500
action=sniff-tzsp chain=postrouting dst-address=p.p.p.p protocol=ipsec-esp sniff-target=s.s.s.s sniff-target-port=37008

Then, run Wireshark on the server, or run tcpdump saving the packets into a file with -s 0 there, with capture filter udp port 37008, of course capturing on the interface with address s.s.s.s, and do the laboratory exercise (let the phone connect and wait until the connection breaks).

The capture will contain IPsec control packets, IPsec transport packets, and the plaintext L2TP packets, both outgoing (before encryption) and incoming (after decryption). So we (actually, you, as you probably don't want to disclose your public IP) should see everything in Wireshark, i.e. what the L2TP server and the phone actually send to each other inside the IPsec transport packets. Except for the address, everything else should be harmless if you use a temporary username and password at the L2TP level. The IPsec PSK cannot be retrieved unless it's really short and/or unless you work for NSA. So if you prefer, you may use TraceWrangler to anonymize the IP addresses in the pcap file and post it here. Or you may decide you trust me a bit more than an ordinary visitor of this forum and we may exchange contacts in a secure way so that I could see the original trace. It's up to you. But if you choose to send the capture to me, say so soon, as otherwise the contact exchange will take place tomorrow

076Lucas · Tue Nov 19, 2019 10:51 pm

So I just created a hotspot with my Android and connected a laptop to it. Configured the VPN connection on the laptop and connected to the hotspot. And wonder well the VPN just stays connected! So I think it is maybe a buggy Android implementation. What kind of Android device do you use JordanReich?

Do you know any standalone VPN app? I tried several, but cannot find a good one that is just a VPN client that you can use to connect to your own router...

Also tried the sniffer cmdlets but I do net get any output. How is that possible?

JordanReich · Tue Nov 19, 2019 11:47 pm

So I just created a hotspot with my Android and connected a laptop to it. Configured the VPN connection on the laptop and connected to the hotspot. And wonder well the VPN just stays connected! So I think it is maybe a buggy Android implementation. What kind of Android device do you use JordanReich?

Do you know any standalone VPN app? I tried several, but cannot find a good one that is just a VPN client that you can use to connect to your own router...

Also tried the sniffer cmdlets but I do net get any output. How is that possible?

I use the Pixel 3 - Running Android 10 - Nov 5 Patch

I have not been able to find any good VPN clients outside of that which is configured in the phone. I am also using MDM in my environment so I have a need to publish with the VPN options that are built into the device specifically.

JordanReich · Tue Nov 19, 2019 11:49 pm

I have an accessible server farm. So we can run whatever tests you need to run. Not a problem.
OK then. Assume p.p.p.p is the remote IP from (behind) which the phone establishes the L2TP/IPsec connection, and s.s.s.s is the address of the server which will do the sniffing. So place the following four rules to the very beginning of their respective chains in /ip firewall mangle:

action=sniff-tzsp chain=prerouting dst-port=500,1701,4500 protocol=udp sniff-target=s.s.s.s sniff-target-port=37008 src-address=p.p.p.p
action=sniff-tzsp chain=prerouting protocol=ipsec-esp sniff-target=s.s.s.s sniff-target-port=37008 src-address=p.p.p.p

action=sniff-tzsp chain=postrouting dst-address=p.p.p.p protocol=udp sniff-target=s.s.s.s sniff-target-port=37008 src-port=500,1701,4500
action=sniff-tzsp chain=postrouting dst-address=p.p.p.p protocol=ipsec-esp sniff-target=s.s.s.s sniff-target-port=37008

Then, run Wireshark on the server, or run tcpdump saving the packets into a file with -s 0 there, with capture filter udp port 37008, of course capturing on the interface with address s.s.s.s, and do the laboratory exercise (let the phone connect and wait until the connection breaks).

The capture will contain IPsec control packets, IPsec transport packets, and the plaintext L2TP packets, both outgoing (before encryption) and incoming (after decryption). So we (actually, you, as you probably don't want to disclose your public IP) should see everything in Wireshark, i.e. what the L2TP server and the phone actually send to each other inside the IPsec transport packets. Except for the address, everything else should be harmless if you use a temporary username and password at the L2TP level. The IPsec PSK cannot be retrieved unless it's really short and/or unless you work for NSA. So if you prefer, you may use TraceWrangler to anonymize the IP addresses in the pcap file and post it here. Or you may decide you trust me a bit more than an ordinary visitor of this forum and we may exchange contacts in a secure way so that I could see the original trace. It's up to you. But if you choose to send the capture to me, say so soon, as otherwise the contact exchange will take place tomorrow

I think I follow you. Give me a bit to see what I can compile for you and will touch base soon. I am also going to flag MikroTik support on this forum topic as well. Depending upon what we find this appears to be an issue that expands just beyond these case scenarios.

sindy · Wed Nov 20, 2019 6:58 pm

So I just created a hotspot with my Android and connected a laptop to it. Configured the VPN connection on the laptop and connected to the hotspot. And wonder well the VPN just stays connected! So I think it is maybe a buggy Android implementation.

@076Lucas, what you've tested proves that there is no issue with the network path between the Tik and the Android phone. But it is still possible that the behaviour of the Android L2TP/IPsec client is standards-compliant but the Tik's IPsec/L2TP stack doesn't understand it. That's why I want to see the capture, as if it is an issue at Tik side, it should be fixed.

JordanReich · Wed Nov 20, 2019 8:25 pm

OK then. Assume p.p.p.p is the remote IP from (behind) which the phone establishes the L2TP/IPsec connection

Working on this now. But quick clarification. The s.s.s.s would refer to the server such as 10.0.0.53 in this case. The p.p.p.p do you mean the public IP address facing the internet or the IP address that is assigned to the phone once it has been established such as the 172.32.0.22 range that I use in this case. I would proceed with the latter being the assumption. But if this is not the case please let me know.

Nevermind after some testing it became fairly obvious the P.P.P.P needed to be the public IP of the phone coming into the router for connection as the mangle rules started to show packet data passing through them. Should have some results shortly, hopefully.

Thanks!

JordanReich · Wed Nov 20, 2019 9:59 pm

Got the log!
I can send it to you do you have a preferred place you'd like to receive it?

sindy · Wed Nov 20, 2019 10:37 pm

It depends on how many people you want to see it. If you don't mind your public IP to leak, you can post it anywhere where it can be accessed with no credentials. If it should be "for my eyes only", since PM doesn't work here, read this howto and if it is no problem for you, use the method they suggest at line 16 (for the short file with a password) to encrypt a short file with your e-mail address using my public key below and post here a hexdump of the encrypted version.

.pem code

JordanReich · Wed Nov 20, 2019 10:51 pm

Let's just make life easy!

*OLD LINK REMOVED*

Let me know when you have a copy of the file.

Thanks.

sindy · Wed Nov 20, 2019 10:57 pm

No idea what you did, but the packets are truncated to some 60 bytes so totally useless for the purpose. Did you run tcpdump with -s 0 ?

JordanReich · Wed Nov 20, 2019 11:02 pm

No idea what you did, but the packets are truncated to some 60 bytes so totally useless for the purpose. Did you run tcpdump with -s 0 ?

Might know what happened. Try it now.

New Link - *LINK REMOVED*

sindy · Wed Nov 20, 2019 11:25 pm

Got it, you can remove it.

JordanReich · Wed Nov 20, 2019 11:25 pm

Got it, you can remove it.

Done! Thanks Sindy. As a reference ...

159.* - Public IP of the phone
198.* - Public IP of the router
172.32.0.100 - Subnet LAN for the phone
10.* - Default LAN of the router
10.0.0.9 - Storage NAS (which is what I was accessing from the phone VPN)

sindy · Wed Nov 20, 2019 11:59 pm

Something is still wrong, because I can only see the packets sent by the phone, and not a single packet sent by the router. Including transport packets, not just the payload. Are the mangle postrouting rules correct?

076Lucas · Thu Nov 21, 2019 10:03 am

Thanks for both of all your effort you are putting into this. If I can help somewhere please let me know.

sindy · Thu Nov 21, 2019 10:33 am

@JordanReich, while taking the new .pcap, please take the log in parallel. In the last (unidirectional) .pcap, I could not find even the first response to the PPP HELLO keepalive, although other PPP control packets were there, whereas in the log taken during another connection attempt the response fo the first HELLO was present. So I need to have the log and .pcap from the same connection attempt.

JordanReich · Thu Nov 21, 2019 5:04 pm

@JordanReich, while taking the new .pcap, please take the log in parallel. In the last (unidirectional) .pcap, I could not find even the first response to the PPP HELLO keepalive, although other PPP control packets were there, whereas in the log taken during another connection attempt the response fo the first HELLO was present. So I need to have the log and .pcap from the same connection attempt.

I believe I figured out the issue with the original trace. I had all four rules set as prerouting I have adjusted the final two so they are set to postrouting. I assume you mean the log I took originally in the other forum post indicating the time of the connection and the hang-up. Can do. If you mean something else please let me know. I'll provide both shortly.

sindy · Thu Nov 21, 2019 5:08 pm

I assume you mean the log I took originally in the other forum post indicating the time of the connection and the hang-up.

Yes, that's the one I had in mind. Routes intended for postrouting placed in prerouting are also a clear culprit so no mystery left.

JordanReich · Thu Nov 21, 2019 5:17 pm

Alright ...

L2TP Log:

# nov/21/2019  7: 8:45 by RouterOS 6.44.5
# software id = 1SBQ-KUIK
#
07:08:49 ipsec,info respond new phase 1 (Identity Protection): ROUTER-IP[500]<=>PHONE-IP[25781] 
07:08:49 ipsec,info ISAKMP-SA established ROUTER-IP[4500]-PHONE-IP[13642] spi:fdbc3ec801e5d071:cad20757f6b7721a 
07:08:51 l2tp,info first L2TP UDP packet received from PHONE-IP 
07:08:51 l2tp,ppp,info,account admin_bypass logged in, 172.32.0.100 
07:08:51 l2tp,ppp,info <l2tp-admin_bypass>: authenticated 
07:08:51 l2tp,ppp,info <l2tp-admin_bypass>: connected 
07:10:15 l2tp,ppp,info <l2tp-admin_bypass>: terminating... - hungup 
07:10:15 l2tp,ppp,info,account admin_bypass logged out, 84 6310976 401431233 148120 288050 
07:10:15 l2tp,ppp,info <l2tp-admin_bypass>: disconnected

My current mangle rules per your instructions are ...

3    chain=prerouting action=sniff-tzsp sniff-target=10.0.0.53 sniff-target-port=37008 protocol=udp src-address=PHONE-IP dst-port=500,1701,4500 log=no log-prefix="" 
 4    chain=prerouting action=sniff-tzsp sniff-target=10.0.0.53 sniff-target-port=37008 protocol=ipsec-esp src-address=PHONE-IP log=no log-prefix="" 
 5    chain=postrouting action=sniff-tzsp sniff-target=10.0.0.53 sniff-target-port=37008 protocol=udp dst-address=PHONE-IP src-port=500,1701,4500 log=no log-prefix="" 
 6    chain=postrouting action=sniff-tzsp sniff-target=10.0.0.53 sniff-target-port=37008 protocol=ipsec-esp dst-address=PHONE-IP log=no log-prefix=""

Traffic passed through them from the test ...
Both zero's are the ipsec-esp protocol rules

 3    prerouting                                                                                                                                                                                    sniff-tzsp                   31 421 352         296 886
 4    prerouting                                                                                                                                                                                    sniff-tzsp                            0               0
 5    postrouting                                                                                                                                                                                   sniff-tzsp                  839 167 653         576 174
 6    postrouting                                                                                                                                                                                   sniff-tzsp                            0               0

Download the Android Trace Here - *LINK REMOVED*
As before please let me know once you've grabbed a copy

Thanks!

sindy · Thu Nov 21, 2019 5:33 pm

Downloaded, opens, you may remove it.

JordanReich · Thu Nov 21, 2019 5:35 pm

Downloaded, opens, you may remove it.

Done! Thanks again.

sindy · Thu Nov 21, 2019 5:54 pm

sheeeet... the first log in this topic is with l2tp debug on (/system logging add topics=l2tp) but it comes from @076Lucas, and I've missed that. There, we can see
Nov/15/2019 22:49:52 l2tp,ppp,debug,packet L2TPDBG===>: <X.X.X.X>: sent LCP EchoReq id=0x7
...
Nov/15/2019 22:49:52 l2tp,ppp,debug,packet L2TPDBG===>: <X.X.X.X>: rcvd LCP EchoRep id=0x7
(and an unresponded Message-Type=HELLO which is because it's a log from about the time when it failed, not from the start)

In your log matching the file, there are just info messages which don't show the individual messages sent. So we've just transported a gigabyte of data in vain

Because I again cannot see those LCP EchoReq/EchoRep messages in the capture and they should be there. So I want to understand whether the sniff-tzsp rules are ignoring part of the traffic or whether in your case there is really some other issue (no idea what it could be).

I won't be able to test how it behaves in my lab until I get there. So please, can activate l2tp logging at debug level as shown above and do one more try...

JordanReich · Thu Nov 21, 2019 5:59 pm

sheeeet... the first log in this topic is with l2tp debug on (/system logging add topics=l2tp) but it comes from @076Lucas, and I've missed that. There, we can see
Nov/15/2019 22:49:52 l2tp,ppp,debug,packet L2TPDBG===>: <X.X.X.X>: sent LCP EchoReq id=0x7
...
Nov/15/2019 22:49:52 l2tp,ppp,debug,packet L2TPDBG===>: <X.X.X.X>: rcvd LCP EchoRep id=0x7
(and an unresponded Message-Type=HELLO which is because it's a log from about the time when it failed, not from the start)

In your log matching the file, there are just info messages which don't show the individual messages sent. So we've just transported a gigabyte of data in vain Because I again cannot see those LCP EchoReq/EchoRep messages in the capture and they should be there. So I want to understand whether the sniff-tzsp rules are ignoring part of the traffic or whether in your case there is really some other issue (no idea what it could be).

I won't be able to test how it behaves in my lab until I get there. So please, can activate l2tp logging at debug level as shown above and do one more try...

Not a problem! I have adjusted my logging rules with the following turned on. I will rerun and provide the results shortly.

LoggingRules.png

Zacharias · Thu Nov 21, 2019 6:04 pm

Did you try to lets say create the vpn client on your computer and see if the behavior is the same ?
If i understood right mikrotik is used as vpn client right ?

JordanReich · Thu Nov 21, 2019 6:07 pm

Did you try to lets say create the vpn client on your computer and see if the behavior is the same ?
If i understood right mikrotik is used as vpn client right ?

Yes, the router is the L2TP/IPSEC VPN server.

The VPN clients have no issues on any other device other than Android mobile communication that I have the ability to test.
Site-to-Site Mikrotik client to Mikrotik server router connections are fine, and windows VPN connections also have no problem.

sindy · Thu Nov 21, 2019 6:07 pm

Not a problem! I have adjusted my logging rules with the following turned on. I will rerun and provide the results shortly.

@JordanReich, I was also writing the following in some other thread, so I better repeat it here:

To get all of the log, before the connection attempt, run the following:
/log print follow-only file=l2tp-log where topics~"l2tp"
Once the VPN connection fails, break the log print command and then download the resulting text file.

sindy · Thu Nov 21, 2019 6:10 pm

Did you try to lets say create the vpn client on your computer and see if the behavior is the same ?
If i understood right mikrotik is used as vpn client right ?

@Zacharias, in my lab, I have one Mikrotik as a L2TP/IPsec server and the other one as a L2TP/IPsec client. I was testing the sniff-tzsp rules there but I cannot remember whether that keepalive stuff was visible in the result.

JordanReich · Thu Nov 21, 2019 6:10 pm

sheeeet... the first log in this topic is with l2tp debug on (/system logging add topics=l2tp) but it comes from @076Lucas, and I've missed that. There, we can see
Nov/15/2019 22:49:52 l2tp,ppp,debug,packet L2TPDBG===>: <X.X.X.X>: sent LCP EchoReq id=0x7
...
Nov/15/2019 22:49:52 l2tp,ppp,debug,packet L2TPDBG===>: <X.X.X.X>: rcvd LCP EchoRep id=0x7
(and an unresponded Message-Type=HELLO which is because it's a log from about the time when it failed, not from the start)

In your log matching the file, there are just info messages which don't show the individual messages sent. So we've just transported a gigabyte of data in vain Because I again cannot see those LCP EchoReq/EchoRep messages in the capture and they should be there. So I want to understand whether the sniff-tzsp rules are ignoring part of the traffic or whether in your case there is really some other issue (no idea what it could be).

I won't be able to test how it behaves in my lab until I get there. So please, can activate l2tp logging at debug level as shown above and do one more try...

Alright ...

L2TP Logging Information...

# nov/21/2019  8: 1:21 by RouterOS 6.44.5
# software id = 1SBQ-KUIK
#
08:01:24 ipsec,debug ===== received 724 bytes from PHONE-IP[47940] to ROUTER-IP[500] 
08:01:24 ipsec,debug,packet eacda968 633ab46e 00000000 00000000 01100200 00000000 000002d4 0d00023c 
08:01:24 ipsec,debug,packet 00000001 00000001 00000230 01010010 03000024 01010000 800b0001 800c7080 
08:01:24 ipsec,debug,packet 80010007 800e0100 80030001 80020005 80040002 03000024 02010000 800b0001 
08:01:24 ipsec,debug,packet 800c7080 80010007 800e0100 80030001 80020004 80040002 03000024 03010000 
08:01:24 ipsec,debug,packet 800b0001 800c7080 80010007 800e0100 80030001 80020006 80040002 03000024 
08:01:24 ipsec,debug,packet 04010000 800b0001 800c7080 80010007 800e0100 80030001 80020002 80040002 
08:01:24 ipsec,debug,packet 03000024 05010000 800b0001 800c7080 80010007 800e0100 80030001 80020001 
08:01:24 ipsec,debug,packet 80040002 03000024 06010000 800b0001 800c7080 80010007 800e0080 80030001 
08:01:24 ipsec,debug,packet 80020006 80040002 03000024 07010000 800b0001 800c7080 80010007 800e0080 
08:01:24 ipsec,debug,packet 80030001 80020005 80040002 03000024 08010000 800b0001 800c7080 80010007 
08:01:24 ipsec,debug,packet 800e0080 80030001 80020004 80040002 03000024 09010000 800b0001 800c7080 
08:01:24 ipsec,debug,packet 80010007 800e0080 80030001 80020002 80040002 03000024 0a010000 800b0001 
08:01:24 ipsec,debug,packet 800c7080 80010007 800e0080 80030001 80020001 80040002 03000020 0b010000 
08:01:24 ipsec,debug,packet 800b0001 800c7080 80010005 80030001 80020004 80040002 03000020 0c010000 
08:01:24 ipsec,debug,packet 800b0001 800c7080 80010005 80030001 80020002 80040002 03000020 0d010000 
08:01:24 ipsec,debug,packet 800b0001 800c7080 80010005 80030001 80020001 80040002 03000020 0e010000 
08:01:24 ipsec,debug,packet 800b0001 800c7080 80010001 80030001 80020004 80040002 03000020 0f010000 
08:01:24 ipsec,debug,packet 800b0001 800c7080 80010001 80030001 80020002 80040002 00000020 10010000 
08:01:24 ipsec,debug,packet 800b0001 800c7080 80010001 80030001 80020001 80040002 0d000014 4a131c81 
08:01:24 ipsec,debug,packet 07035845 5c5728f2 0e95452f 0d000014 cd604643 35df21f8 7cfdb2fc 68b6a448 
08:01:24 ipsec,debug,packet 0d000014 90cb8091 3ebb696e 086381b5 ec427b1f 0d000014 4485152d 18b6bbcd 
08:01:24 ipsec,debug,packet 0be8a846 9579ddcc 0d000018 4048b7d5 6ebce885 25e7de7f 00d6c2d3 80000000 
08:01:24 ipsec,debug,packet 00000014 afcad713 68a1f1c9 6b8696fc 77570100 
08:01:24 ipsec,debug === 
08:01:24 ipsec,info respond new phase 1 (Identity Protection): ROUTER-IP[500]<=>PHONE-IP[47940] 
08:01:24 ipsec,debug begin. 
08:01:24 ipsec,debug seen nptype=1(sa) len=572 
08:01:24 ipsec,debug seen nptype=13(vid) len=20 
08:01:24 ipsec,debug seen nptype=13(vid) len=20 
08:01:24 ipsec,debug seen nptype=13(vid) len=20 
08:01:24 ipsec,debug seen nptype=13(vid) len=20 
08:01:24 ipsec,debug seen nptype=13(vid) len=24 
08:01:24 ipsec,debug seen nptype=13(vid) len=20 
08:01:24 ipsec,debug succeed. 
08:01:24 ipsec received Vendor ID: RFC 3947 
08:01:24 ipsec received Vendor ID: draft-ietf-ipsec-nat-t-ike-02 
08:01:24 ipsec received Vendor ID: draft-ietf-ipsec-nat-t-ike-02\n 
08:01:24 ipsec received Vendor ID: draft-ietf-ipsec-nat-t-ike-00 
08:01:24 ipsec received long Microsoft ID: FRAGMENTATION 
08:01:24 ipsec Fragmentation enabled 
08:01:24 ipsec received Vendor ID: DPD 
08:01:24 ipsec,debug remote supports DPD 
08:01:24 ipsec PHONE-IP Selected NAT-T version: RFC 3947 
08:01:24 ipsec,debug total SA len=568 
08:01:24 ipsec,debug 00000001 00000001 00000230 01010010 03000024 01010000 800b0001 800c7080 
08:01:24 ipsec,debug 80010007 800e0100 80030001 80020005 80040002 03000024 02010000 800b0001 
08:01:24 ipsec,debug 800c7080 80010007 800e0100 80030001 80020004 80040002 03000024 03010000 
08:01:24 ipsec,debug 800b0001 800c7080 80010007 800e0100 80030001 80020006 80040002 03000024 
08:01:24 ipsec,debug 04010000 800b0001 800c7080 80010007 800e0100 80030001 80020002 80040002 
08:01:24 ipsec,debug 03000024 05010000 800b0001 800c7080 80010007 800e0100 80030001 80020001 
08:01:24 ipsec,debug 80040002 03000024 06010000 800b0001 800c7080 80010007 800e0080 80030001 
08:01:24 ipsec,debug 80020006 80040002 03000024 07010000 800b0001 800c7080 80010007 800e0080 
08:01:24 ipsec,debug 80030001 80020005 80040002 03000024 08010000 800b0001 800c7080 80010007 
08:01:24 ipsec,debug 800e0080 80030001 80020004 80040002 03000024 09010000 800b0001 800c7080 
08:01:24 ipsec,debug 80010007 800e0080 80030001 80020002 80040002 03000024 0a010000 800b0001 
08:01:24 ipsec,debug 800c7080 80010007 800e0080 80030001 80020001 80040002 03000020 0b010000 
08:01:24 ipsec,debug 800b0001 800c7080 80010005 80030001 80020004 80040002 03000020 0c010000 
08:01:24 ipsec,debug 800b0001 800c7080 80010005 80030001 80020002 80040002 03000020 0d010000 
08:01:24 ipsec,debug 800b0001 800c7080 80010005 80030001 80020001 80040002 03000020 0e010000 
08:01:24 ipsec,debug 800b0001 800c7080 80010001 80030001 80020004 80040002 03000020 0f010000 
08:01:24 ipsec,debug 800b0001 800c7080 80010001 80030001 80020002 80040002 00000020 10010000 
08:01:24 ipsec,debug 800b0001 800c7080 80010001 80030001 80020001 80040002 
08:01:24 ipsec,debug begin. 
08:01:24 ipsec,debug seen nptype=2(prop) len=560 
08:01:24 ipsec,debug succeed. 
08:01:24 ipsec,debug proposal #1 len=560 
08:01:24 ipsec,debug begin. 
08:01:24 ipsec,debug seen nptype=3(trns) len=36 
08:01:24 ipsec,debug seen nptype=3(trns) len=36 
08:01:24 ipsec,debug seen nptype=3(trns) len=36 
08:01:24 ipsec,debug seen nptype=3(trns) len=36 
08:01:24 ipsec,debug seen nptype=3(trns) len=36 
08:01:24 ipsec,debug seen nptype=3(trns) len=36 
08:01:24 ipsec,debug seen nptype=3(trns) len=36 
08:01:24 ipsec,debug seen nptype=3(trns) len=36 
08:01:24 ipsec,debug seen nptype=3(trns) len=36 
08:01:24 ipsec,debug seen nptype=3(trns) len=36 
08:01:24 ipsec,debug seen nptype=3(trns) len=32 
08:01:24 ipsec,debug seen nptype=3(trns) len=32 
08:01:24 ipsec,debug seen nptype=3(trns) len=32 
08:01:24 ipsec,debug seen nptype=3(trns) len=32 
08:01:24 ipsec,debug seen nptype=3(trns) len=32 
08:01:24 ipsec,debug seen nptype=3(trns) len=32 
08:01:24 ipsec,debug succeed. 
08:01:24 ipsec,debug transform #1 len=36 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=5 
08:01:24 ipsec invalied hash algorithm=5. 
08:01:24 ipsec,debug transform #2 len=36 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=4 
08:01:24 ipsec,debug hash(sha2_256) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #3 len=36 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=6 
08:01:24 ipsec,debug hash(sha2_512) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #4 len=36 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=SHA 
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #5 len=36 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=MD5 
08:01:24 ipsec,debug hash(md5) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #6 len=36 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=6 
08:01:24 ipsec,debug hash(sha2_512) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #7 len=36 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=5 
08:01:24 ipsec invalied hash algorithm=5. 
08:01:24 ipsec,debug transform #8 len=36 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=4 
08:01:24 ipsec,debug hash(sha2_256) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #9 len=36 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=SHA 
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #10 len=36 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=MD5 
08:01:24 ipsec,debug hash(md5) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #11 len=32 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC 
08:01:24 ipsec,debug encryption(3des) 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=4 
08:01:24 ipsec,debug hash(sha2_256) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #12 len=32 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC 
08:01:24 ipsec,debug encryption(3des) 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=SHA 
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #13 len=32 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC 
08:01:24 ipsec,debug encryption(3des) 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=MD5 
08:01:24 ipsec,debug hash(md5) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #14 len=32 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=DES-CBC 
08:01:24 ipsec,debug encryption(des) 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=4 
08:01:24 ipsec,debug hash(sha2_256) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #15 len=32 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=DES-CBC 
08:01:24 ipsec,debug encryption(des) 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=SHA 
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug transform #16 len=32 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=DES-CBC 
08:01:24 ipsec,debug encryption(des) 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=MD5 
08:01:24 ipsec,debug hash(md5) 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug pair 1: 
08:01:24 ipsec,debug  0x209528: next=(nil) tnext=0x88408 
08:01:24 ipsec,debug   0x88408: next=(nil) tnext=0x1eb160 
08:01:24 ipsec,debug    0x1eb160: next=(nil) tnext=0x1eb178 
08:01:24 ipsec,debug     0x1eb178: next=(nil) tnext=0x1eb0c0 
08:01:24 ipsec,debug      0x1eb0c0: next=(nil) tnext=0x1eb0d8 
08:01:24 ipsec,debug       0x1eb0d8: next=(nil) tnext=0x212f48 
08:01:24 ipsec,debug        0x212f48: next=(nil) tnext=0x212f60 
08:01:24 ipsec,debug         0x212f60: next=(nil) tnext=0x212f78 
08:01:24 ipsec,debug          0x212f78: next=(nil) tnext=0x212f90 
08:01:24 ipsec,debug           0x212f90: next=(nil) tnext=0x2046a0 
08:01:24 ipsec,debug            0x2046a0: next=(nil) tnext=0x2046b8 
08:01:24 ipsec,debug             0x2046b8: next=(nil) tnext=0x2046d0 
08:01:24 ipsec,debug              0x2046d0: next=(nil) tnext=0x2046e8 
08:01:24 ipsec,debug               0x2046e8: next=(nil) tnext=(nil) 
08:01:24 ipsec,debug proposal #1: 14 transform 
08:01:24 ipsec,debug -checking with pre-shared key auth- 
08:01:24 ipsec,debug prop#=1, prot-id=ISAKMP, spi-size=0, #trns=16 
08:01:24 ipsec,debug trns#=2, trns-id=IKE 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=4 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug -compare proposal #1: Local:Peer 
08:01:24 ipsec,debug (lifetime = 86400:28800) 
08:01:24 ipsec,debug (lifebyte = 0:0) 
08:01:24 ipsec,debug enctype = AES-CBC:AES-CBC 
08:01:24 ipsec,debug (encklen = 256:256) 
08:01:24 ipsec,debug hashtype = SHA:4 
08:01:24 ipsec,debug authmethod = pre-shared key:pre-shared key 
08:01:24 ipsec,debug dh_group = 2048-bit MODP group:1024-bit MODP group 
08:01:24 ipsec,debug -compare proposal #2: Local:Peer 
08:01:24 ipsec,debug (lifetime = 86400:28800) 
08:01:24 ipsec,debug (lifebyte = 0:0) 
08:01:24 ipsec,debug enctype = AES-CBC:AES-CBC 
08:01:24 ipsec,debug (encklen = 256:256) 
08:01:24 ipsec,debug hashtype = SHA:4 
08:01:24 ipsec,debug authmethod = pre-shared key:pre-shared key 
08:01:24 ipsec,debug dh_group = 1024-bit MODP group:1024-bit MODP group 
08:01:24 ipsec,debug -compare proposal #3: Local:Peer 
08:01:24 ipsec,debug (lifetime = 86400:28800) 
08:01:24 ipsec,debug (lifebyte = 0:0) 
08:01:24 ipsec,debug enctype = 3DES-CBC:AES-CBC 
08:01:24 ipsec,debug (encklen = 0:256) 
08:01:24 ipsec,debug hashtype = SHA:4 
08:01:24 ipsec,debug authmethod = pre-shared key:pre-shared key 
08:01:24 ipsec,debug dh_group = 2048-bit MODP group:1024-bit MODP group 
08:01:24 ipsec,debug -compare proposal #4: Local:Peer 
08:01:24 ipsec,debug (lifetime = 86400:28800) 
08:01:24 ipsec,debug (lifebyte = 0:0) 
08:01:24 ipsec,debug enctype = 3DES-CBC:AES-CBC 
08:01:24 ipsec,debug (encklen = 0:256) 
08:01:24 ipsec,debug hashtype = SHA:4 
08:01:24 ipsec,debug authmethod = pre-shared key:pre-shared key 
08:01:24 ipsec,debug dh_group = 1024-bit MODP group:1024-bit MODP group 
08:01:24 ipsec,debug prop#=1, prot-id=ISAKMP, spi-size=0, #trns=16 
08:01:24 ipsec,debug trns#=3, trns-id=IKE 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=6 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug -compare proposal #1: Local:Peer 
08:01:24 ipsec,debug (lifetime = 86400:28800) 
08:01:24 ipsec,debug (lifebyte = 0:0) 
08:01:24 ipsec,debug enctype = AES-CBC:AES-CBC 
08:01:24 ipsec,debug (encklen = 256:256) 
08:01:24 ipsec,debug hashtype = SHA:6 
08:01:24 ipsec,debug authmethod = pre-shared key:pre-shared key 
08:01:24 ipsec,debug dh_group = 2048-bit MODP group:1024-bit MODP group 
08:01:24 ipsec,debug -compare proposal #2: Local:Peer 
08:01:24 ipsec,debug (lifetime = 86400:28800) 
08:01:24 ipsec,debug (lifebyte = 0:0) 
08:01:24 ipsec,debug enctype = AES-CBC:AES-CBC 
08:01:24 ipsec,debug (encklen = 256:256) 
08:01:24 ipsec,debug hashtype = SHA:6 
08:01:24 ipsec,debug authmethod = pre-shared key:pre-shared key 
08:01:24 ipsec,debug dh_group = 1024-bit MODP group:1024-bit MODP group 
08:01:24 ipsec,debug -compare proposal #3: Local:Peer 
08:01:24 ipsec,debug (lifetime = 86400:28800) 
08:01:24 ipsec,debug (lifebyte = 0:0) 
08:01:24 ipsec,debug enctype = 3DES-CBC:AES-CBC 
08:01:24 ipsec,debug (encklen = 0:256) 
08:01:24 ipsec,debug hashtype = SHA:6 
08:01:24 ipsec,debug authmethod = pre-shared key:pre-shared key 
08:01:24 ipsec,debug dh_group = 2048-bit MODP group:1024-bit MODP group 
08:01:24 ipsec,debug -compare proposal #4: Local:Peer 
08:01:24 ipsec,debug (lifetime = 86400:28800) 
08:01:24 ipsec,debug (lifebyte = 0:0) 
08:01:24 ipsec,debug enctype = 3DES-CBC:AES-CBC 
08:01:24 ipsec,debug (encklen = 0:256) 
08:01:24 ipsec,debug hashtype = SHA:6 
08:01:24 ipsec,debug authmethod = pre-shared key:pre-shared key 
08:01:24 ipsec,debug dh_group = 1024-bit MODP group:1024-bit MODP group 
08:01:24 ipsec,debug prop#=1, prot-id=ISAKMP, spi-size=0, #trns=16 
08:01:24 ipsec,debug trns#=4, trns-id=IKE 
08:01:24 ipsec,debug type=Life Type, flag=0x8000, lorv=seconds 
08:01:24 ipsec,debug type=Life Duration, flag=0x8000, lorv=28800 
08:01:24 ipsec,debug type=Encryption Algorithm, flag=0x8000, lorv=AES-CBC 
08:01:24 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:24 ipsec,debug type=Authentication Method, flag=0x8000, lorv=pre-shared key 
08:01:24 ipsec,debug type=Hash Algorithm, flag=0x8000, lorv=SHA 
08:01:24 ipsec,debug type=Group Description, flag=0x8000, lorv=1024-bit MODP group 
08:01:24 ipsec,debug -compare proposal #1: Local:Peer 
08:01:24 ipsec,debug (lifetime = 86400:28800) 
08:01:24 ipsec,debug (lifebyte = 0:0) 
08:01:24 ipsec,debug enctype = AES-CBC:AES-CBC 
08:01:24 ipsec,debug (encklen = 256:256) 
08:01:24 ipsec,debug hashtype = SHA:SHA 
08:01:24 ipsec,debug authmethod = pre-shared key:pre-shared key 
08:01:24 ipsec,debug dh_group = 2048-bit MODP group:1024-bit MODP group 
08:01:24 ipsec,debug -compare proposal #2: Local:Peer 
08:01:24 ipsec,debug (lifetime = 86400:28800) 
08:01:24 ipsec,debug (lifebyte = 0:0) 
08:01:24 ipsec,debug enctype = AES-CBC:AES-CBC 
08:01:24 ipsec,debug (encklen = 256:256) 
08:01:24 ipsec,debug hashtype = SHA:SHA 
08:01:24 ipsec,debug authmethod = pre-shared key:pre-shared key 
08:01:24 ipsec,debug dh_group = 1024-bit MODP group:1024-bit MODP group 
08:01:24 ipsec,debug -an acceptable proposal found- 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug -agreed on pre-shared key auth- 
08:01:24 ipsec,debug === 
08:01:24 ipsec,debug new cookie: 
08:01:24 ipsec,debug 8916a29a2614ded1\01 
08:01:24 ipsec,debug add payload of len 52, next type 13 
08:01:24 ipsec,debug add payload of len 16, next type 13 
08:01:24 ipsec,debug add payload of len 16, next type 13 
08:01:24 ipsec,debug add payload of len 20, next type 0 
08:01:24 ipsec,debug 148 bytes from ROUTER-IP[500] to PHONE-IP[47940] 
08:01:24 ipsec,debug 1 times of 148 bytes message will be sent to PHONE-IP[47940] 
08:01:24 ipsec,debug,packet eacda968 633ab46e 8916a29a 2614ded1 01100200 00000000 00000094 0d000038 
08:01:24 ipsec,debug,packet 00000001 00000001 0000002c 01010001 00000024 04010000 800b0001 800c7080 
08:01:24 ipsec,debug,packet 80010007 800e0100 80030001 80020002 80040002 0d000014 4a131c81 07035845 
08:01:24 ipsec,debug,packet 5c5728f2 0e95452f 0d000014 afcad713 68a1f1c9 6b8696fc 77570100 00000018 
08:01:24 ipsec,debug,packet 4048b7d5 6ebce885 25e7de7f 00d6c2d3 80000000 
08:01:24 ipsec sent phase1 packet ROUTER-IP[500]<=>PHONE-IP[47940] eacda968633ab46e:8916a29a2614ded1 
08:01:24 ipsec,debug ===== received 228 bytes from PHONE-IP[47940] to ROUTER-IP[500] 
08:01:24 ipsec,debug,packet eacda968 633ab46e 8916a29a 2614ded1 04100200 00000000 000000e4 0a000084 
08:01:24 ipsec,debug,packet c934dd22 65544f64 01e71804 9dff7463 3f0ebdbd 52061a1d 5f7c7f22 42cf40ad 
08:01:24 ipsec,debug,packet 14548b4b 5694a6c5 515e2f05 be065501 76e5b05b ab6570e4 2dac866b 92f341c4 
08:01:24 ipsec,debug,packet 201c2833 a572c82f a9603be1 c416fa54 8762a5d6 00f23689 c4678963 26893ec3 
08:01:24 ipsec,debug,packet 3233b1b1 93a83a96 d2f89e8b fd3e050e 89ebcea0 d6f37dca 89ce6c5f b518aaf9 
08:01:24 ipsec,debug,packet 14000014 f3740f6f 657e6542 d47cc4f9 60993258 14000018 41aad3a9 e2c3dd79 
08:01:24 ipsec,debug,packet 8966b7dc 00cb5a82 f83d3172 00000018 dd5bdf59 6ae8e999 390d2593 c076ed60 
08:01:24 ipsec,debug,packet 65def750 
08:01:24 ipsec,debug begin. 
08:01:24 ipsec,debug seen nptype=4(ke) len=132 
08:01:24 ipsec,debug seen nptype=10(nonce) len=20 
08:01:24 ipsec,debug seen nptype=20(nat-d) len=24 
08:01:24 ipsec,debug seen nptype=20(nat-d) len=24 
08:01:24 ipsec,debug succeed. 
08:01:24 ipsec ROUTER-IP Hashing ROUTER-IP[500] with algo #2  
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec NAT-D payload #0 verified 
08:01:24 ipsec PHONE-IP Hashing PHONE-IP[47940] with algo #2  
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec NAT-D payload #1 doesn't match 
08:01:24 ipsec NAT detected: PEER 
08:01:24 ipsec,debug === 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug compute DH's private. 
08:01:24 ipsec,debug 5646f4dd 2ba2f293 210dad12 4adfa212 29052a8c 01f14828 441225b1 a2ff3681 
08:01:24 ipsec,debug ee0f64a8 b59b6972 98df889b 323c994f a6966563 4e90b42d 21d4ffd4 c647e5ea 
08:01:24 ipsec,debug 361227ac e2de81b5 68bdcf1b d155388f 5efb7de2 e830d204 134b6e7c 92890ac5 
08:01:24 ipsec,debug babaf3f3 f34473d5 43343db6 2779b500 331cd2e6 b0315cea c9f9002e 3f0579ab 
08:01:24 ipsec,debug compute DH's public. 
08:01:24 ipsec,debug 98e98c9f 13cc7456 82d86bb8 ca4a3481 e584225e b7d00673 d269ba6a 6ccb5adc 
08:01:24 ipsec,debug 92bb5de6 5dea2c9b 234e0c11 0ae137f2 064470b3 f4cb2955 d7a79e6f dc517276 
08:01:24 ipsec,debug 66a5e20d 795c1d4e 2de0abab cafb5827 b9f37b66 31aba6ae 7fb0008d 0a28b151 
08:01:24 ipsec,debug 3f57ce93 208f8d6e ed07b128 fae10d50 6a41da85 55ec0cef 9fbc8270 6e603e57 
08:01:24 ipsec PHONE-IP Hashing PHONE-IP[47940] with algo #2  
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec ROUTER-IP Hashing ROUTER-IP[500] with algo #2  
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec Adding remote and local NAT-D payloads. 
08:01:24 ipsec,debug add payload of len 128, next type 10 
08:01:24 ipsec,debug add payload of len 24, next type 20 
08:01:24 ipsec,debug add payload of len 20, next type 20 
08:01:24 ipsec,debug add payload of len 20, next type 0 
08:01:24 ipsec,debug 236 bytes from ROUTER-IP[500] to PHONE-IP[47940] 
08:01:24 ipsec,debug 1 times of 236 bytes message will be sent to PHONE-IP[47940] 
08:01:24 ipsec,debug,packet eacda968 633ab46e 8916a29a 2614ded1 04100200 00000000 000000ec 0a000084 
08:01:24 ipsec,debug,packet 98e98c9f 13cc7456 82d86bb8 ca4a3481 e584225e b7d00673 d269ba6a 6ccb5adc 
08:01:24 ipsec,debug,packet 92bb5de6 5dea2c9b 234e0c11 0ae137f2 064470b3 f4cb2955 d7a79e6f dc517276 
08:01:24 ipsec,debug,packet 66a5e20d 795c1d4e 2de0abab cafb5827 b9f37b66 31aba6ae 7fb0008d 0a28b151 
08:01:24 ipsec,debug,packet 3f57ce93 208f8d6e ed07b128 fae10d50 6a41da85 55ec0cef 9fbc8270 6e603e57 
08:01:24 ipsec,debug,packet 1400001c bcd3376d c257018d 40d3417e 3b1ecc9e 72fea42c 08bcff48 14000018 
08:01:24 ipsec,debug,packet fb45b6c1 2bd38a1b 62c86191 dc0120df d56678e3 00000018 41aad3a9 e2c3dd79 
08:01:24 ipsec,debug,packet 8966b7dc 00cb5a82 f83d3172 
08:01:24 ipsec sent phase1 packet ROUTER-IP[500]<=>PHONE-IP[47940] eacda968633ab46e:8916a29a2614ded1 
08:01:24 ipsec,debug dh(modp1024) 
08:01:24 ipsec,debug compute DH's shared. 
08:01:24 ipsec,debug 
08:01:24 ipsec,debug 0ed91e55 3d64b050 c502f154 d5ce0a62 b8368130 b22584af 7628cf1d 3c831c06 
08:01:24 ipsec,debug 67161d89 2fb86399 49d75793 61ea1ab6 c86ba803 5ee75edd 6865c6e3 6266c0b6 
08:01:24 ipsec,debug f3fea375 20211443 99e8f86e 16dabb46 24aa5008 b4b8d382 44cbfe2f c501b4db 
08:01:24 ipsec,debug bc58c03b e635b9af b2ac56cd 6e4e64ce c67f22e1 fd6e56fb aca474f4 8bc91175 
08:01:24 ipsec,debug nonce 1:  
08:01:24 ipsec,debug f3740f6f 657e6542 d47cc4f9 60993258 
08:01:24 ipsec,debug nonce 2:  
08:01:24 ipsec,debug bcd3376d c257018d 40d3417e 3b1ecc9e 72fea42c 08bcff48 
08:01:24 ipsec,debug hmac(hmac_sha1) 
08:01:24 ipsec,debug SKEYID computed: 
08:01:24 ipsec,debug 77af2edc aeac96a9 91160a14 db498284 5cf75f68 
08:01:24 ipsec,debug hmac(hmac_sha1) 
08:01:24 ipsec,debug SKEYID_d computed: 
08:01:24 ipsec,debug b6f9dc2c 209d19db 828ba0b5 55e7a25b 46f041a9 
08:01:24 ipsec,debug hmac(hmac_sha1) 
08:01:24 ipsec,debug SKEYID_a computed: 
08:01:24 ipsec,debug fd57ea0f 4d00c87f 52e15eda 6e636295 edf85eb8 
08:01:24 ipsec,debug hmac(hmac_sha1) 
08:01:24 ipsec,debug SKEYID_e computed: 
08:01:24 ipsec,debug 4b97d43d 03c8c13f d0364735 5f17eb8c a26ae61a 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec,debug len(SKEYID_e) < len(Ka) (20 < 32), generating long key (Ka = K1 | K2 | ...) 
08:01:24 ipsec,debug hmac(hmac_sha1) 
08:01:24 ipsec,debug compute intermediate encryption key K1 
08:01:24 ipsec,debug 00 
08:01:24 ipsec,debug 296567b0 7a68be27 bc878fee 779b2f8c 05a2e1eb 
08:01:24 ipsec,debug hmac(hmac_sha1) 
08:01:24 ipsec,debug compute intermediate encryption key K2 
08:01:24 ipsec,debug 296567b0 7a68be27 bc878fee 779b2f8c 05a2e1eb 
08:01:24 ipsec,debug d30f6ffa c4594fbb 4fba873e deedc982 af45535f 
08:01:24 ipsec,debug final encryption key computed: 
08:01:24 ipsec,debug 296567b0 7a68be27 bc878fee 779b2f8c 05a2e1eb d30f6ffa c4594fbb 4fba873e 
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug IV computed: 
08:01:24 ipsec,debug 2ab5fc6c 82a1fd85 ea82b81e c1d75e80 
08:01:24 ipsec,debug ===== received 92 bytes from PHONE-IP[13642] to ROUTER-IP[4500] 
08:01:24 ipsec,debug,packet eacda968 633ab46e 8916a29a 2614ded1 05100201 00000000 0000005c 4c0aeaf0 
08:01:24 ipsec,debug,packet c73847d5 0a7134b8 4d993d6f 6a652b79 f94fc3da 4d01c9b8 8baa102d 1d3380a5 
08:01:24 ipsec,debug,packet 4de05fef 5bc57978 863318ec 5fd7d3ae 6c9d5c27 e69f8635 bf9a4bff 
08:01:24 ipsec NAT-T: ports changed to: PHONE-IP[13642]<=>ROUTER-IP[4500] 
08:01:24 ipsec KA list add: ROUTER-IP[4500]->PHONE-IP[13642] 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug IV was saved for next processing: 
08:01:24 ipsec,debug 5fd7d3ae 6c9d5c27 e69f8635 bf9a4bff 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug with key: 
08:01:24 ipsec,debug 296567b0 7a68be27 bc878fee 779b2f8c 05a2e1eb d30f6ffa c4594fbb 4fba873e 
08:01:24 ipsec,debug decrypted payload by IV: 
08:01:24 ipsec,debug 2ab5fc6c 82a1fd85 ea82b81e c1d75e80 
08:01:24 ipsec,debug decrypted payload, but not trimed. 
08:01:24 ipsec,debug 0800000c 011101f4 0a19980c 00000018 79a48182 95b85517 df9a47b9 8b36b83d 
08:01:24 ipsec,debug a615835a 95f6bcb7 e9a7f6af fa9480a5 9bd29cdf b8d59fae dec5e1c6 83cf811b 
08:01:24 ipsec,debug padding len=28 
08:01:24 ipsec,debug skip to trim padding. 
08:01:24 ipsec,debug decrypted. 
08:01:24 ipsec,debug eacda968 633ab46e 8916a29a 2614ded1 05100201 00000000 0000005c 0800000c 
08:01:24 ipsec,debug 011101f4 0a19980c 00000018 79a48182 95b85517 df9a47b9 8b36b83d a615835a 
08:01:24 ipsec,debug 95f6bcb7 e9a7f6af fa9480a5 9bd29cdf b8d59fae dec5e1c6 83cf811b 
08:01:24 ipsec,debug begin. 
08:01:24 ipsec,debug seen nptype=5(id) len=12 
08:01:24 ipsec,debug seen nptype=8(hash) len=24 
08:01:24 ipsec,debug succeed. 
08:01:24 ipsec,debug HASH received: 
08:01:24 ipsec,debug 79a48182 95b85517 df9a47b9 8b36b83d a615835a 
08:01:24 ipsec,debug HASH with: 
08:01:24 ipsec,debug c934dd22 65544f64 01e71804 9dff7463 3f0ebdbd 52061a1d 5f7c7f22 42cf40ad 
08:01:24 ipsec,debug 14548b4b 5694a6c5 515e2f05 be065501 76e5b05b ab6570e4 2dac866b 92f341c4 
08:01:24 ipsec,debug 201c2833 a572c82f a9603be1 c416fa54 8762a5d6 00f23689 c4678963 26893ec3 
08:01:24 ipsec,debug 3233b1b1 93a83a96 d2f89e8b fd3e050e 89ebcea0 d6f37dca 89ce6c5f b518aaf9 
08:01:24 ipsec,debug 98e98c9f 13cc7456 82d86bb8 ca4a3481 e584225e b7d00673 d269ba6a 6ccb5adc 
08:01:24 ipsec,debug 92bb5de6 5dea2c9b 234e0c11 0ae137f2 064470b3 f4cb2955 d7a79e6f dc517276 
08:01:24 ipsec,debug 66a5e20d 795c1d4e 2de0abab cafb5827 b9f37b66 31aba6ae 7fb0008d 0a28b151 
08:01:24 ipsec,debug 3f57ce93 208f8d6e ed07b128 fae10d50 6a41da85 55ec0cef 9fbc8270 6e603e57 
08:01:24 ipsec,debug eacda968 633ab46e 8916a29a 2614ded1 00000001 00000001 00000230 01010010 
08:01:24 ipsec,debug 03000024 01010000 800b0001 800c7080 80010007 800e0100 80030001 80020005 
08:01:24 ipsec,debug 80040002 03000024 02010000 800b0001 800c7080 80010007 800e0100 80030001 
08:01:24 ipsec,debug 80020004 80040002 03000024 03010000 800b0001 800c7080 80010007 800e0100 
08:01:24 ipsec,debug 80030001 80020006 80040002 03000024 04010000 800b0001 800c7080 80010007 
08:01:24 ipsec,debug 800e0100 80030001 80020002 80040002 03000024 05010000 800b0001 800c7080 
08:01:24 ipsec,debug 80010007 800e0100 80030001 80020001 80040002 03000024 06010000 800b0001 
08:01:24 ipsec,debug 800c7080 80010007 800e0080 80030001 80020006 80040002 03000024 07010000 
08:01:24 ipsec,debug 800b0001 800c7080 80010007 800e0080 80030001 80020005 80040002 03000024 
08:01:24 ipsec,debug 08010000 800b0001 800c7080 80010007 800e0080 80030001 80020004 80040002 
08:01:24 ipsec,debug 03000024 09010000 800b0001 800c7080 80010007 800e0080 80030001 80020002 
08:01:24 ipsec,debug 80040002 03000024 0a010000 800b0001 800c7080 80010007 800e0080 80030001 
08:01:24 ipsec,debug 80020001 80040002 03000020 0b010000 800b0001 800c7080 80010005 80030001 
08:01:24 ipsec,debug 80020004 80040002 03000020 0c010000 800b0001 800c7080 80010005 80030001 
08:01:24 ipsec,debug 80020002 80040002 03000020 0d010000 800b0001 800c7080 80010005 80030001 
08:01:24 ipsec,debug 80020001 80040002 03000020 0e010000 800b0001 800c7080 80010001 80030001 
08:01:24 ipsec,debug 80020004 80040002 03000020 0f010000 800b0001 800c7080 80010001 80030001 
08:01:24 ipsec,debug 80020002 80040002 00000020 10010000 800b0001 800c7080 80010001 80030001 
08:01:24 ipsec,debug 80020001 80040002 011101f4 0a19980c 
08:01:24 ipsec,debug hmac(hmac_sha1) 
08:01:24 ipsec,debug HASH computed: 
08:01:24 ipsec,debug 79a48182 95b85517 df9a47b9 8b36b83d a615835a 
08:01:24 ipsec,debug HASH for PSK validated. 
08:01:24 ipsec,debug PHONE-IP peer's ID 
08:01:24 ipsec,debug 011101f4 0a19980c 
08:01:24 ipsec,debug === 
08:01:24 ipsec,debug use ID type of IPv4_address 
08:01:24 ipsec,debug generate HASH_R 
08:01:24 ipsec,debug HASH with: 
08:01:24 ipsec,debug 98e98c9f 13cc7456 82d86bb8 ca4a3481 e584225e b7d00673 d269ba6a 6ccb5adc 
08:01:24 ipsec,debug 92bb5de6 5dea2c9b 234e0c11 0ae137f2 064470b3 f4cb2955 d7a79e6f dc517276 
08:01:24 ipsec,debug 66a5e20d 795c1d4e 2de0abab cafb5827 b9f37b66 31aba6ae 7fb0008d 0a28b151 
08:01:24 ipsec,debug 3f57ce93 208f8d6e ed07b128 fae10d50 6a41da85 55ec0cef 9fbc8270 6e603e57 
08:01:24 ipsec,debug c934dd22 65544f64 01e71804 9dff7463 3f0ebdbd 52061a1d 5f7c7f22 42cf40ad 
08:01:24 ipsec,debug 14548b4b 5694a6c5 515e2f05 be065501 76e5b05b ab6570e4 2dac866b 92f341c4 
08:01:24 ipsec,debug 201c2833 a572c82f a9603be1 c416fa54 8762a5d6 00f23689 c4678963 26893ec3 
08:01:24 ipsec,debug 3233b1b1 93a83a96 d2f89e8b fd3e050e 89ebcea0 d6f37dca 89ce6c5f b518aaf9 
08:01:24 ipsec,debug 8916a29a 2614ded1 eacda968 633ab46e 00000001 00000001 00000230 01010010 
08:01:24 ipsec,debug 03000024 01010000 800b0001 800c7080 80010007 800e0100 80030001 80020005 
08:01:24 ipsec,debug 80040002 03000024 02010000 800b0001 800c7080 80010007 800e0100 80030001 
08:01:24 ipsec,debug 80020004 80040002 03000024 03010000 800b0001 800c7080 80010007 800e0100 
08:01:24 ipsec,debug 80030001 80020006 80040002 03000024 04010000 800b0001 800c7080 80010007 
08:01:24 ipsec,debug 800e0100 80030001 80020002 80040002 03000024 05010000 800b0001 800c7080 
08:01:24 ipsec,debug 80010007 800e0100 80030001 80020001 80040002 03000024 06010000 800b0001 
08:01:24 ipsec,debug 800c7080 80010007 800e0080 80030001 80020006 80040002 03000024 07010000 
08:01:24 ipsec,debug 800b0001 800c7080 80010007 800e0080 80030001 80020005 80040002 03000024 
08:01:24 ipsec,debug 08010000 800b0001 800c7080 80010007 800e0080 80030001 80020004 80040002 
08:01:24 ipsec,debug 03000024 09010000 800b0001 800c7080 80010007 800e0080 80030001 80020002 
08:01:24 ipsec,debug 80040002 03000024 0a010000 800b0001 800c7080 80010007 800e0080 80030001 
08:01:24 ipsec,debug 80020001 80040002 03000020 0b010000 800b0001 800c7080 80010005 80030001 
08:01:24 ipsec,debug 80020004 80040002 03000020 0c010000 800b0001 800c7080 80010005 80030001 
08:01:24 ipsec,debug 80020002 80040002 03000020 0d010000 800b0001 800c7080 80010005 80030001 
08:01:24 ipsec,debug 80020001 80040002 03000020 0e010000 800b0001 800c7080 80010001 80030001 
08:01:24 ipsec,debug 80020004 80040002 03000020 0f010000 800b0001 800c7080 80010001 80030001 
08:01:24 ipsec,debug 80020002 80040002 00000020 10010000 800b0001 800c7080 80010001 80030001 
08:01:24 ipsec,debug 80020001 80040002 011101f4 c60f07db 
08:01:24 ipsec,debug hmac(hmac_sha1) 
08:01:24 ipsec,debug HASH computed: 
08:01:24 ipsec,debug 0f012cd3 7500a23a 40c30389 c8004b7c eb369fbd 
08:01:24 ipsec,debug add payload of len 8, next type 8 
08:01:24 ipsec,debug add payload of len 20, next type 0 
08:01:24 ipsec,debug begin encryption. 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug pad length = 12 
08:01:24 ipsec,debug 0800000c 011101f4 c60f07db 00000018 0f012cd3 7500a23a 40c30389 c8004b7c 
08:01:24 ipsec,debug eb369fbd fcdfecd7 bcfcd4f8 e9dcae0b 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug with key: 
08:01:24 ipsec,debug 296567b0 7a68be27 bc878fee 779b2f8c 05a2e1eb d30f6ffa c4594fbb 4fba873e 
08:01:24 ipsec,debug encrypted payload by IV: 
08:01:24 ipsec,debug 5fd7d3ae 6c9d5c27 e69f8635 bf9a4bff 
08:01:24 ipsec,debug save IV for next: 
08:01:24 ipsec,debug 85c0b38c 29284d1b 4f3e132d 92560411 
08:01:24 ipsec,debug encrypted. 
08:01:24 ipsec,debug 76 bytes from ROUTER-IP[4500] to PHONE-IP[13642] 
08:01:24 ipsec,debug 1 times of 80 bytes message will be sent to PHONE-IP[13642] 
08:01:24 ipsec,debug,packet eacda968 633ab46e 8916a29a 2614ded1 05100201 00000000 0000004c d158ef25 
08:01:24 ipsec,debug,packet 4f20847f 532a3e8c 30fe3190 6159c239 5ba02959 25c4388d 6884474e 85c0b38c 
08:01:24 ipsec,debug,packet 29284d1b 4f3e132d 92560411 
08:01:24 ipsec,info ISAKMP-SA established ROUTER-IP[4500]-PHONE-IP[13642] spi:eacda968633ab46e:8916a29a2614ded1 
08:01:24 ipsec,debug === 
08:01:24 ipsec,debug ===== received 108 bytes from PHONE-IP[13642] to ROUTER-IP[4500] 
08:01:24 ipsec,debug,packet eacda968 633ab46e 8916a29a 2614ded1 08100501 eb2d3ae5 0000006c 424eac8e 
08:01:24 ipsec,debug,packet e4bc501b 4afdeacd ccd039d4 a66e6290 81de28fe 753e5159 4186596d 437840bd 
08:01:24 ipsec,debug,packet bea05aac 606427bb 27207ff8 54979e4c eba1264d bde3412a 4d4ce544 bac8b2d0 
08:01:24 ipsec,debug,packet 609d724b 99d8a321 0e7ef96c 
08:01:24 ipsec,debug receive Information. 
08:01:24 ipsec,debug compute IV for phase2 
08:01:24 ipsec,debug phase1 last IV: 
08:01:24 ipsec,debug 85c0b38c 29284d1b 4f3e132d 92560411 eb2d3ae5 
08:01:24 ipsec,debug hash(sha1) 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug phase2 IV computed: 
08:01:24 ipsec,debug 9ed7fbea 96026c97 3a5297d5 03d6642b 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug IV was saved for next processing: 
08:01:24 ipsec,debug bac8b2d0 609d724b 99d8a321 0e7ef96c 
08:01:24 ipsec,debug encryption(aes) 
08:01:24 ipsec,debug with key: 
08:01:24 ipsec,debug 296567b0 7a68be27 bc878fee 779b2f8c 05a2e1eb d30f6ffa c4594fbb 4fba873e 
08:01:24 ipsec,debug decrypted payload by IV: 
08:01:24 ipsec,debug 9ed7fbea 96026c97 3a5297d5 03d6642b 
08:01:24 ipsec,debug decrypted payload, but not trimed. 
08:01:24 ipsec,debug 0b000018 3b16fc87 89f14440 64fea29a 7902030d bcd327c6 0000001c 00000001 
08:01:24 ipsec,debug 01106002 eacda968 633ab46e 8916a29a 2614ded1 cca0bac3 b6a8ede0 9e83b7f0 
08:01:24 ipsec,debug d0f992dc eec2d489 889ea0eb a5e3ff1b 
08:01:24 ipsec,debug padding len=28 
08:01:24 ipsec,debug skip to trim padding. 
08:01:24 ipsec,debug decrypted. 
08:01:24 ipsec,debug eacda968 633ab46e 8916a29a 2614ded1 08100501 eb2d3ae5 0000006c 0b000018 
08:01:24 ipsec,debug 3b16fc87 89f14440 64fea29a 7902030d bcd327c6 0000001c 00000001 01106002 
08:01:24 ipsec,debug eacda968 633ab46e 8916a29a 2614ded1 cca0bac3 b6a8ede0 9e83b7f0 d0f992dc 
08:01:24 ipsec,debug eec2d489 889ea0eb a5e3ff1b 
08:01:24 ipsec,debug HASH with: 
08:01:24 ipsec,debug eb2d3ae5 0000001c 00000001 01106002 eacda968 633ab46e 8916a29a 2614ded1 
08:01:24 ipsec,debug hmac(hmac_sha1) 
08:01:24 ipsec,debug HASH computed: 
08:01:24 ipsec,debug 3b16fc87 89f14440 64fea29a 7902030d bcd327c6 
08:01:24 ipsec,debug hash validated. 
08:01:24 ipsec,debug begin. 
08:01:24 ipsec,debug seen nptype=8(hash) len=24 
08:01:24 ipsec,debug seen nptype=11(notify) len=28 
08:01:24 ipsec,debug succeed. 
08:01:24 ipsec,debug PHONE-IP notify: INITIAL-CONTACT 
08:01:25 ipsec,debug ===== received 668 bytes from PHONE-IP[13642] to ROUTER-IP[4500] 
08:01:25 ipsec,debug,packet eacda968 633ab46e 8916a29a 2614ded1 08102001 c096b477 0000029c 7e2c2f87 
08:01:25 ipsec,debug,packet 7bbaa137 1869ee1c aa98d7eb b2e20daa 9005d883 bcca5d0e 70742733 f3b178af 
08:01:25 ipsec,debug,packet f4c5eaa2 27bcfa8c b4ea8bea d7af6a2b ff5e0e36 6157a851 f92a68e3 6f67ba63 
08:01:25 ipsec,debug,packet 7c78d703 3ed2f34f 8df7b531 01ecd595 87ace6fa ca383427 f0980fe4 ee719fab 
08:01:25 ipsec,debug,packet c18d1aed a50b4a09 97f0abba 62087682 87589e63 490fd4db 11a5e96a 7ad65279 
08:01:25 ipsec,debug,packet 15caf1e1 c75b9361 07813489 895dad79 d09f080c aab76a6e 88e6236a 1a21fa8b 
08:01:25 ipsec,debug,packet 1a2ac71b f004c51f 05e32ead 763772bb c19e6c23 3c69f971 af387384 8fcaae7f 
08:01:25 ipsec,debug,packet f49b0560 9b5c1ab4 c39657be 3c019bca 5ed7602a 360085d1 9c211d4a f8a8424f 
08:01:25 ipsec,debug,packet 13ea462c 2ee9c8da ae5b4e54 e7165d9c 569190bf 79bb7a92 fa2e3561 2f934b28 
08:01:25 ipsec,debug,packet af550155 e2a970ac a40c4b61 f1b843f7 641c35c7 4f3a906e 00deded9 fe79ff20 
08:01:25 ipsec,debug,packet 200ba64c 8ea03e43 f00a0529 fa45181a f18380ae 5a18561a 93a9814a b8a176e6 
08:01:25 ipsec,debug,packet 29baa8a9 1386e524 d8d2c36b a97a0e2a 9528ac5c cb17aac7 9610c92f e818e355 
08:01:25 ipsec,debug,packet 6fa07099 784be3d3 16989c19 6f9c870a ca520a4e b849a870 2b1f72b1 348f0d1b 
08:01:25 ipsec,debug,packet e2b6e722 3780b1e5 a8043788 3a2dfc15 5ec7b46b c9a7b515 9384b806 b6f84e33 
08:01:25 ipsec,debug,packet 64a2ccf7 fc16e0c0 5e74a7fe 60c60de7 e17dbde2 ccc04a14 f12fcd2e ff220da3 
08:01:25 ipsec,debug,packet 6a980d07 3041808f e5242dc1 781f7657 02252090 8927bd81 2230d7e6 8dda18d5 
08:01:25 ipsec,debug,packet 0fc26902 6f831e1c 1303985f d6e2c973 aa2aa16a 1c4d3fd4 5be77e27 e99d2549 
08:01:25 ipsec,debug,packet c0164edc 9fd6307c ec9b2813 a21591c0 09ef6d2a 38d874c8 0b48c068 e79c82b8 
08:01:25 ipsec,debug,packet 7d0eda07 da8d0d8b 0870f268 f91a4591 91d67b6b 285a7bdd 7f635ae1 cc4f2f7d 
08:01:25 ipsec,debug,packet f2d8af95 8d72dc84 fcdfb86c 0a912c95 9c115980 1b43e1eb 0de7f310 dfc3857b 
08:01:25 ipsec,debug,packet 81784b53 9fa8b181 9ba90723 c8ae00cb 76e0dcc5 5bcf2922 b257893b 
08:01:25 ipsec,debug compute IV for phase2 
08:01:25 ipsec,debug phase1 last IV: 
08:01:25 ipsec,debug 85c0b38c 29284d1b 4f3e132d 92560411 c096b477 
08:01:25 ipsec,debug hash(sha1) 
08:01:25 ipsec,debug encryption(aes) 
08:01:25 ipsec,debug phase2 IV computed: 
08:01:25 ipsec,debug 7481036f 5a4f31ca 6b8a683c 811c1873 
08:01:25 ipsec,debug === 
08:01:25 ipsec respond new phase 2 negotiation: ROUTER-IP[4500]<=>PHONE-IP[13642] 
08:01:25 ipsec,debug encryption(aes) 
08:01:25 ipsec,debug IV was saved for next processing: 
08:01:25 ipsec,debug c8ae00cb 76e0dcc5 5bcf2922 b257893b 
08:01:25 ipsec,debug encryption(aes) 
08:01:25 ipsec,debug with key: 
08:01:25 ipsec,debug 296567b0 7a68be27 bc878fee 779b2f8c 05a2e1eb d30f6ffa c4594fbb 4fba873e 
08:01:25 ipsec,debug decrypted payload by IV: 
08:01:25 ipsec,debug 7481036f 5a4f31ca 6b8a683c 811c1873 
08:01:25 ipsec,debug decrypted payload, but not trimed. 
08:01:25 ipsec,debug 01000018 b6b64892 62029244 04d0f735 0b561cf9 7cf4d195 0a000220 00000001 
08:01:25 ipsec,debug 00000001 00000214 01030414 0f0e7207 0300001c 010c0000 80010001 80027080 
08:01:25 ipsec,debug 80040004 80060100 80050007 0300001c 020c0000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80060100 80050006 0300001c 030c0000 80010001 80027080 80040004 80060100 
08:01:25 ipsec,debug 80050002 0300001c 040c0000 80010001 80027080 80040004 80060100 80050005 
08:01:25 ipsec,debug 0300001c 050c0000 80010001 80027080 80040004 80060100 80050001 0300001c 
08:01:25 ipsec,debug 060c0000 80010001 80027080 80040004 80060080 80050007 0300001c 070c0000 
08:01:25 ipsec,debug 80010001 80027080 80040004 80060080 80050006 0300001c 080c0000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80060080 80050002 0300001c 090c0000 80010001 80027080 
08:01:25 ipsec,debug 80040004 80060080 80050005 0300001c 0a0c0000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80060080 80050001 03000018 0b030000 80010001 80027080 80040004 80050007 
08:01:25 ipsec,debug 03000018 0c030000 80010001 80027080 80040004 80050006 03000018 0d030000 
08:01:25 ipsec,debug 80010001 80027080 80040004 80050002 03000018 0e030000 80010001 80027080 
08:01:25 ipsec,debug 80040004 80050005 03000018 0f030000 80010001 80027080 80040004 80050001 
08:01:25 ipsec,debug 03000018 10020000 80010001 80027080 80040004 80050007 03000018 11020000 
08:01:25 ipsec,debug 80010001 80027080 80040004 80050006 03000018 12020000 80010001 80027080 
08:01:25 ipsec,debug 80040004 80050002 03000018 13020000 80010001 80027080 80040004 80050005 
08:01:25 ipsec,debug 00000018 14020000 80010001 80027080 80040004 80050001 05000014 9513cba2 
08:01:25 ipsec,debug 659bbf33 49387246 5d679ee3 0500000c 01110000 0a19980c 0000000c 011106a5 
08:01:25 ipsec,debug c60f07db 90bbb8e0 b1f09fe7 fd8cfdfc adacdba6 dced8eb3 d8ec8ba6 9183931b 
08:01:25 ipsec,debug padding len=28 
08:01:25 ipsec,debug skip to trim padding. 
08:01:25 ipsec,debug decrypted. 
08:01:25 ipsec,debug eacda968 633ab46e 8916a29a 2614ded1 08102001 c096b477 0000029c 01000018 
08:01:25 ipsec,debug b6b64892 62029244 04d0f735 0b561cf9 7cf4d195 0a000220 00000001 00000001 
08:01:25 ipsec,debug 00000214 01030414 0f0e7207 0300001c 010c0000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80060100 80050007 0300001c 020c0000 80010001 80027080 80040004 80060100 
08:01:25 ipsec,debug 80050006 0300001c 030c0000 80010001 80027080 80040004 80060100 80050002 
08:01:25 ipsec,debug 0300001c 040c0000 80010001 80027080 80040004 80060100 80050005 0300001c 
08:01:25 ipsec,debug 050c0000 80010001 80027080 80040004 80060100 80050001 0300001c 060c0000 
08:01:25 ipsec,debug 80010001 80027080 80040004 80060080 80050007 0300001c 070c0000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80060080 80050006 0300001c 080c0000 80010001 80027080 
08:01:25 ipsec,debug 80040004 80060080 80050002 0300001c 090c0000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80060080 80050005 0300001c 0a0c0000 80010001 80027080 80040004 80060080 
08:01:25 ipsec,debug 80050001 03000018 0b030000 80010001 80027080 80040004 80050007 03000018 
08:01:25 ipsec,debug 0c030000 80010001 80027080 80040004 80050006 03000018 0d030000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80050002 03000018 0e030000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80050005 03000018 0f030000 80010001 80027080 80040004 80050001 03000018 
08:01:25 ipsec,debug 10020000 80010001 80027080 80040004 80050007 03000018 11020000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80050006 03000018 12020000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80050002 03000018 13020000 80010001 80027080 80040004 80050005 00000018 
08:01:25 ipsec,debug 14020000 80010001 80027080 80040004 80050001 05000014 9513cba2 659bbf33 
08:01:25 ipsec,debug 49387246 5d679ee3 0500000c 01110000 0a19980c 0000000c 011106a5 c60f07db 
08:01:25 ipsec,debug 90bbb8e0 b1f09fe7 fd8cfdfc adacdba6 dced8eb3 d8ec8ba6 9183931b 
08:01:25 ipsec,debug begin. 
08:01:25 ipsec,debug seen nptype=8(hash) len=24 
08:01:25 ipsec,debug seen nptype=1(sa) len=544 
08:01:25 ipsec,debug seen nptype=10(nonce) len=20 
08:01:25 ipsec,debug seen nptype=5(id) len=12 
08:01:25 ipsec,debug seen nptype=5(id) len=12 
08:01:25 ipsec,debug succeed. 
08:01:25 ipsec,debug received IDci2: 
08:01:25 ipsec,debug 01110000 0a19980c 
08:01:25 ipsec,debug received IDcr2: 
08:01:25 ipsec,debug 011106a5 c60f07db 
08:01:25 ipsec,debug HASH(1) validate: 
08:01:25 ipsec,debug b6b64892 62029244 04d0f735 0b561cf9 7cf4d195 
08:01:25 ipsec,debug HASH with: 
08:01:25 ipsec,debug c096b477 0a000220 00000001 00000001 00000214 01030414 0f0e7207 0300001c 
08:01:25 ipsec,debug 010c0000 80010001 80027080 80040004 80060100 80050007 0300001c 020c0000 
08:01:25 ipsec,debug 80010001 80027080 80040004 80060100 80050006 0300001c 030c0000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80060100 80050002 0300001c 040c0000 80010001 80027080 
08:01:25 ipsec,debug 80040004 80060100 80050005 0300001c 050c0000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80060100 80050001 0300001c 060c0000 80010001 80027080 80040004 80060080 
08:01:25 ipsec,debug 80050007 0300001c 070c0000 80010001 80027080 80040004 80060080 80050006 
08:01:25 ipsec,debug 0300001c 080c0000 80010001 80027080 80040004 80060080 80050002 0300001c 
08:01:25 ipsec,debug 090c0000 80010001 80027080 80040004 80060080 80050005 0300001c 0a0c0000 
08:01:25 ipsec,debug 80010001 80027080 80040004 80060080 80050001 03000018 0b030000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80050007 03000018 0c030000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80050006 03000018 0d030000 80010001 80027080 80040004 80050002 03000018 
08:01:25 ipsec,debug 0e030000 80010001 80027080 80040004 80050005 03000018 0f030000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80050001 03000018 10020000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80050007 03000018 11020000 80010001 80027080 80040004 80050006 03000018 
08:01:25 ipsec,debug 12020000 80010001 80027080 80040004 80050002 03000018 13020000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80050005 00000018 14020000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80050001 05000014 9513cba2 659bbf33 49387246 5d679ee3 0500000c 01110000 
08:01:25 ipsec,debug 0a19980c 0000000c 011106a5 c60f07db 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug HASH computed: 
08:01:25 ipsec,debug b6b64892 62029244 04d0f735 0b561cf9 7cf4d195 
08:01:25 ipsec,debug total SA len=540 
08:01:25 ipsec,debug 00000001 00000001 00000214 01030414 0f0e7207 0300001c 010c0000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80060100 80050007 0300001c 020c0000 80010001 80027080 
08:01:25 ipsec,debug 80040004 80060100 80050006 0300001c 030c0000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80060100 80050002 0300001c 040c0000 80010001 80027080 80040004 80060100 
08:01:25 ipsec,debug 80050005 0300001c 050c0000 80010001 80027080 80040004 80060100 80050001 
08:01:25 ipsec,debug 0300001c 060c0000 80010001 80027080 80040004 80060080 80050007 0300001c 
08:01:25 ipsec,debug 070c0000 80010001 80027080 80040004 80060080 80050006 0300001c 080c0000 
08:01:25 ipsec,debug 80010001 80027080 80040004 80060080 80050002 0300001c 090c0000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80060080 80050005 0300001c 0a0c0000 80010001 80027080 
08:01:25 ipsec,debug 80040004 80060080 80050001 03000018 0b030000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80050007 03000018 0c030000 80010001 80027080 80040004 80050006 03000018 
08:01:25 ipsec,debug 0d030000 80010001 80027080 80040004 80050002 03000018 0e030000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80050005 03000018 0f030000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80050001 03000018 10020000 80010001 80027080 80040004 80050007 03000018 
08:01:25 ipsec,debug 11020000 80010001 80027080 80040004 80050006 03000018 12020000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80050002 03000018 13020000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80050005 00000018 14020000 80010001 80027080 80040004 80050001 
08:01:25 ipsec,debug begin. 
08:01:25 ipsec,debug seen nptype=2(prop) len=532 
08:01:25 ipsec,debug succeed. 
08:01:25 ipsec,debug proposal #1 len=532 
08:01:25 ipsec,debug begin. 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug seen nptype=3(trns) len=24 
08:01:25 ipsec,debug seen nptype=3(trns) len=24 
08:01:25 ipsec,debug seen nptype=3(trns) len=24 
08:01:25 ipsec,debug seen nptype=3(trns) len=24 
08:01:25 ipsec,debug seen nptype=3(trns) len=24 
08:01:25 ipsec,debug seen nptype=3(trns) len=24 
08:01:25 ipsec,debug seen nptype=3(trns) len=24 
08:01:25 ipsec,debug seen nptype=3(trns) len=24 
08:01:25 ipsec,debug seen nptype=3(trns) len=24 
08:01:25 ipsec,debug seen nptype=3(trns) len=24 
08:01:25 ipsec,debug succeed. 
08:01:25 ipsec,debug transform #1 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha512 
08:01:25 ipsec,debug transform #2 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=6 
08:01:25 ipsec invalid auth algorithm=6. 
08:01:25 ipsec,debug transform #3 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
08:01:25 ipsec,debug transform #4 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha256 
08:01:25 ipsec,debug transform #5 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-md5 
08:01:25 ipsec,debug transform #6 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha512 
08:01:25 ipsec,debug transform #7 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=6 
08:01:25 ipsec invalid auth algorithm=6. 
08:01:25 ipsec,debug transform #8 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
08:01:25 ipsec,debug transform #9 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha256 
08:01:25 ipsec,debug transform #10 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-md5 
08:01:25 ipsec,debug transform #11 len=24 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha512 
08:01:25 ipsec,debug transform #12 len=24 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=6 
08:01:25 ipsec invalid auth algorithm=6. 
08:01:25 ipsec,debug transform #13 len=24 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
08:01:25 ipsec,debug transform #14 len=24 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha256 
08:01:25 ipsec,debug transform #15 len=24 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-md5 
08:01:25 ipsec,debug transform #16 len=24 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha512 
08:01:25 ipsec,debug transform #17 len=24 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=6 
08:01:25 ipsec invalid auth algorithm=6. 
08:01:25 ipsec,debug transform #18 len=24 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
08:01:25 ipsec,debug transform #19 len=24 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha256 
08:01:25 ipsec,debug transform #20 len=24 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-md5 
08:01:25 ipsec,debug pair 1: 
08:01:25 ipsec,debug  0x209718: next=(nil) tnext=0x205318 
08:01:25 ipsec,debug   0x205318: next=(nil) tnext=0x205330 
08:01:25 ipsec,debug    0x205330: next=(nil) tnext=0x214a08 
08:01:25 ipsec,debug     0x214a08: next=(nil) tnext=0x214a20 
08:01:25 ipsec,debug      0x214a20: next=(nil) tnext=0x214a38 
08:01:25 ipsec,debug       0x214a38: next=(nil) tnext=0x214a50 
08:01:25 ipsec,debug        0x214a50: next=(nil) tnext=0x214a68 
08:01:25 ipsec,debug         0x214a68: next=(nil) tnext=0x214a80 
08:01:25 ipsec,debug          0x214a80: next=(nil) tnext=0x214a98 
08:01:25 ipsec,debug           0x214a98: next=(nil) tnext=0x214ab0 
08:01:25 ipsec,debug            0x214ab0: next=(nil) tnext=0x214ac8 
08:01:25 ipsec,debug             0x214ac8: next=(nil) tnext=0x214ae0 
08:01:25 ipsec,debug              0x214ae0: next=(nil) tnext=0x205088 
08:01:25 ipsec,debug               0x205088: next=(nil) tnext=0x2050a0 
08:01:25 ipsec,debug                0x2050a0: next=(nil) tnext=0x2050b8 
08:01:25 ipsec,debug                 0x2050b8: next=(nil) tnext=(nil) 
08:01:25 ipsec,debug proposal #1: 16 transform 
08:01:25 ipsec,debug got the local address from ID payload ROUTER-IP[1701] prefixlen=32 ul_proto=17 
08:01:25 ipsec,debug got the peer address from ID payload 10.25.152.12[0] prefixlen=32 ul_proto=17 
08:01:25 ipsec,debug updating policy address because of NAT in transport mode 
08:01:25 ipsec,debug new peer address PHONE-IP[0] 
08:01:25 ipsec searching for policy for selector: ROUTER-IP:1701 ip-proto:17 <=> PHONE-IP ip-proto:17 
08:01:25 ipsec generating policy 
08:01:25 ipsec,debug  (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=UDP-Transport reqid=149:149) 
08:01:25 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
08:01:25 ipsec,debug   (trns_id=3DES encklen=0 authtype=hmac-sha1) 
08:01:25 ipsec,debug begin compare proposals. 
08:01:25 ipsec,debug pair[1]: 0x209718 
08:01:25 ipsec,debug  0x209718: next=(nil) tnext=0x205318 
08:01:25 ipsec,debug   0x205318: next=(nil) tnext=0x205330 
08:01:25 ipsec,debug    0x205330: next=(nil) tnext=0x214a08 
08:01:25 ipsec,debug     0x214a08: next=(nil) tnext=0x214a20 
08:01:25 ipsec,debug      0x214a20: next=(nil) tnext=0x214a38 
08:01:25 ipsec,debug       0x214a38: next=(nil) tnext=0x214a50 
08:01:25 ipsec,debug        0x214a50: next=(nil) tnext=0x214a68 
08:01:25 ipsec,debug         0x214a68: next=(nil) tnext=0x214a80 
08:01:25 ipsec,debug          0x214a80: next=(nil) tnext=0x214a98 
08:01:25 ipsec,debug           0x214a98: next=(nil) tnext=0x214ab0 
08:01:25 ipsec,debug            0x214ab0: next=(nil) tnext=0x214ac8 
08:01:25 ipsec,debug             0x214ac8: next=(nil) tnext=0x214ae0 
08:01:25 ipsec,debug              0x214ae0: next=(nil) tnext=0x205088 
08:01:25 ipsec,debug               0x205088: next=(nil) tnext=0x2050a0 
08:01:25 ipsec,debug                0x2050a0: next=(nil) tnext=0x2050b8 
08:01:25 ipsec,debug                 0x2050b8: next=(nil) tnext=(nil) 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=1 trns-id=AES-CBC 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha512 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=3 trns-id=AES-CBC 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=4 trns-id=AES-CBC 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha256 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=5 trns-id=AES-CBC 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-md5 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=6 trns-id=AES-CBC 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha512 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=8 trns-id=AES-CBC 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=9 trns-id=AES-CBC 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha256 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=10 trns-id=AES-CBC 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=128 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-md5 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=11 trns-id=3DES 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha512 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=13 trns-id=3DES 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=14 trns-id=3DES 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha256 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=15 trns-id=3DES 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-md5 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=16 trns-id=DES 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha512 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=18 trns-id=DES 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=19 trns-id=DES 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha256 
08:01:25 ipsec,debug prop#=1 prot-id=ESP spi-size=4 #trns=20 trns#=20 trns-id=DES 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-md5 
08:01:25 ipsec,debug peer's single bundle: 
08:01:25 ipsec,debug  (proto_id=ESP spisize=4 spi=0f0e7207 spi_p=00000000 encmode=UDP-Transport reqid=0:0) 
08:01:25 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha512) 
08:01:25 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
08:01:25 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha256) 
08:01:25 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-md5) 
08:01:25 ipsec,debug   (trns_id=AES-CBC encklen=128 authtype=hmac-sha512) 
08:01:25 ipsec,debug   (trns_id=AES-CBC encklen=128 authtype=hmac-sha1) 
08:01:25 ipsec,debug   (trns_id=AES-CBC encklen=128 authtype=hmac-sha256) 
08:01:25 ipsec,debug   (trns_id=AES-CBC encklen=128 authtype=hmac-md5) 
08:01:25 ipsec,debug   (trns_id=3DES encklen=0 authtype=hmac-sha512) 
08:01:25 ipsec,debug   (trns_id=3DES encklen=0 authtype=hmac-sha1) 
08:01:25 ipsec,debug   (trns_id=3DES encklen=0 authtype=hmac-sha256) 
08:01:25 ipsec,debug   (trns_id=3DES encklen=0 authtype=hmac-md5) 
08:01:25 ipsec,debug   (trns_id=DES encklen=0 authtype=hmac-sha512) 
08:01:25 ipsec,debug   (trns_id=DES encklen=0 authtype=hmac-sha1) 
08:01:25 ipsec,debug   (trns_id=DES encklen=0 authtype=hmac-sha256) 
08:01:25 ipsec,debug   (trns_id=DES encklen=0 authtype=hmac-md5) 
08:01:25 ipsec,debug my single bundle: 
08:01:25 ipsec,debug  (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=UDP-Transport reqid=149:149) 
08:01:25 ipsec,debug   (trns_id=AES-CBC encklen=256 authtype=hmac-sha1) 
08:01:25 ipsec,debug   (trns_id=3DES encklen=0 authtype=hmac-sha1) 
08:01:25 ipsec Adjusting my encmode UDP-Transport->Transport 
08:01:25 ipsec Adjusting peer's encmode UDP-Transport(4)->Transport(2) 
08:01:25 ipsec authtype mismatched: my:hmac-sha1 peer:hmac-sha512 
08:01:25 ipsec trns_id mismatched: my:3DES peer:AES-CBC 
08:01:25 ipsec,debug matched 
08:01:25 ipsec,debug === 
08:01:25 ipsec,debug call pfkey_send_getspi 10cb 
08:01:25 ipsec,debug pfkey GETSPI sent: ESP/Transport PHONE-IP[13642]->ROUTER-IP[4500]  
08:01:25 ipsec,debug pfkey getspi sent. 
08:01:25 ipsec,debug total SA len=48 
08:01:25 ipsec,debug 00000001 00000001 00000028 01030401 00000000 0000001c 030c0000 80010001 
08:01:25 ipsec,debug 80027080 80040004 80060100 80050002 
08:01:25 ipsec,debug begin. 
08:01:25 ipsec,debug seen nptype=2(prop) len=40 
08:01:25 ipsec,debug succeed. 
08:01:25 ipsec,debug proposal #1 len=40 
08:01:25 ipsec,debug begin. 
08:01:25 ipsec,debug seen nptype=3(trns) len=28 
08:01:25 ipsec,debug succeed. 
08:01:25 ipsec,debug transform #3 len=28 
08:01:25 ipsec,debug type=SA Life Type, flag=0x8000, lorv=seconds 
08:01:25 ipsec,debug type=SA Life Duration, flag=0x8000, lorv=28800 
08:01:25 ipsec,debug life duration was in TLV. 
08:01:25 ipsec,debug type=Encryption Mode, flag=0x8000, lorv=UDP-Transport 
08:01:25 ipsec,debug UDP encapsulation requested 
08:01:25 ipsec,debug type=Key Length, flag=0x8000, lorv=256 
08:01:25 ipsec,debug type=Authentication Algorithm, flag=0x8000, lorv=hmac-sha1 
08:01:25 ipsec,debug pair 1: 
08:01:25 ipsec,debug  0x1ffb88: next=(nil) tnext=(nil) 
08:01:25 ipsec,debug proposal #1: 1 transform 
08:01:25 ipsec,debug NAT-OAi: 
08:01:25 ipsec,debug 01000000 9f79ce2f 
08:01:25 ipsec,debug NAT-OAr: 
08:01:25 ipsec,debug 01000000 c60f07db 
08:01:25 ipsec,debug add payload of len 48, next type 10 
08:01:25 ipsec,debug add payload of len 24, next type 5 
08:01:25 ipsec,debug add payload of len 8, next type 5 
08:01:25 ipsec,debug add payload of len 8, next type 21 
08:01:25 ipsec,debug add payload of len 8, next type 21 
08:01:25 ipsec,debug add payload of len 8, next type 0 
08:01:25 ipsec,debug HASH with: 
08:01:25 ipsec,debug c096b477 9513cba2 659bbf33 49387246 5d679ee3 0a000034 00000001 00000001 
08:01:25 ipsec,debug 00000028 01030401 0514fc88 0000001c 030c0000 80010001 80027080 80040004 
08:01:25 ipsec,debug 80060100 80050002 0500001c bd3420dd e445b18c 467f9e30 a17fa564 fbbc7d58 
08:01:25 ipsec,debug 22d61826 0500000c 01110000 0a19980c 1500000c 011106a5 c60f07db 1500000c 
08:01:25 ipsec,debug 01000000 9f79ce2f 0000000c 01000000 c60f07db 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug HASH computed: 
08:01:25 ipsec,debug 7b771474 6a54c483 2d3d515f 8f1994cc cc5efd2e 
08:01:25 ipsec,debug add payload of len 20, next type 1 
08:01:25 ipsec,debug begin encryption. 
08:01:25 ipsec,debug encryption(aes) 
08:01:25 ipsec,debug pad length = 8 
08:01:25 ipsec,debug 01000018 7b771474 6a54c483 2d3d515f 8f1994cc cc5efd2e 0a000034 00000001 
08:01:25 ipsec,debug 00000001 00000028 01030401 0514fc88 0000001c 030c0000 80010001 80027080 
08:01:25 ipsec,debug 80040004 80060100 80050002 0500001c bd3420dd e445b18c 467f9e30 a17fa564 
08:01:25 ipsec,debug fbbc7d58 22d61826 0500000c 01110000 0a19980c 1500000c 011106a5 c60f07db 
08:01:25 ipsec,debug 1500000c 01000000 9f79ce2f 0000000c 01000000 c60f07db b8dd8180 cbf69d07 
08:01:25 ipsec,debug encryption(aes) 
08:01:25 ipsec,debug with key: 
08:01:25 ipsec,debug 296567b0 7a68be27 bc878fee 779b2f8c 05a2e1eb d30f6ffa c4594fbb 4fba873e 
08:01:25 ipsec,debug encrypted payload by IV: 
08:01:25 ipsec,debug c8ae00cb 76e0dcc5 5bcf2922 b257893b 
08:01:25 ipsec,debug save IV for next: 
08:01:25 ipsec,debug a90b2627 f39552a8 83774f40 d59b4f0a 
08:01:25 ipsec,debug encrypted. 
08:01:25 ipsec,debug 188 bytes from ROUTER-IP[4500] to PHONE-IP[13642] 
08:01:25 ipsec,debug 1 times of 192 bytes message will be sent to PHONE-IP[13642] 
08:01:25 ipsec,debug,packet eacda968 633ab46e 8916a29a 2614ded1 08102001 c096b477 000000bc b74fab29 
08:01:25 ipsec,debug,packet 3f70e23f dd173e15 77339d1a a4f69999 f8eb433a cea3d6b9 e01bfbb5 3e37b0b2 
08:01:25 ipsec,debug,packet e30acdbd c084f671 b2697e0a 26a0ae01 a40022af 072784dd 9117ba67 45c7a3bb 
08:01:25 ipsec,debug,packet c94b2b07 47428544 7d6f2f61 bd409138 60ed3a2e d60e9045 eec2d4c7 db551980 
08:01:25 ipsec,debug,packet cc95c350 b28c75c7 6cda3797 b0ac57f1 5fd89832 fe31c6d9 11c43bb1 a534c276 
08:01:25 ipsec,debug,packet 20bc56a8 7be8f2f6 03ca44b8 a90b2627 f39552a8 83774f40 d59b4f0a 
08:01:25 ipsec sent phase2 packet ROUTER-IP[4500]<=>PHONE-IP[13642] eacda968633ab46e:8916a29a2614ded1:0000c096 
08:01:25 ipsec,debug ===== received 76 bytes from PHONE-IP[13642] to ROUTER-IP[4500] 
08:01:25 ipsec,debug,packet eacda968 633ab46e 8916a29a 2614ded1 08102001 c096b477 0000004c 00c3c881 
08:01:25 ipsec,debug,packet 8d1ed7fd 5df36303 74578792 4980ccf3 64dc602d 581fc485 30a5f2a7 330fa1f7 
08:01:25 ipsec,debug,packet 4648c20c 0ac7c595 21137a62 
08:01:25 ipsec,debug encryption(aes) 
08:01:25 ipsec,debug IV was saved for next processing: 
08:01:25 ipsec,debug 330fa1f7 4648c20c 0ac7c595 21137a62 
08:01:25 ipsec,debug encryption(aes) 
08:01:25 ipsec,debug with key: 
08:01:25 ipsec,debug 296567b0 7a68be27 bc878fee 779b2f8c 05a2e1eb d30f6ffa c4594fbb 4fba873e 
08:01:25 ipsec,debug decrypted payload by IV: 
08:01:25 ipsec,debug a90b2627 f39552a8 83774f40 d59b4f0a 
08:01:25 ipsec,debug decrypted payload, but not trimed. 
08:01:25 ipsec,debug 00000018 54a03727 e1121e18 2e92dd5f b1c093a9 0f17f17e 8fae9dee fdefffe2 
08:01:25 ipsec,debug d4d5f7ad fdeac4b4 d48292fd b6a39417 
08:01:25 ipsec,debug padding len=24 
08:01:25 ipsec,debug skip to trim padding. 
08:01:25 ipsec,debug decrypted. 
08:01:25 ipsec,debug eacda968 633ab46e 8916a29a 2614ded1 08102001 c096b477 0000004c 00000018 
08:01:25 ipsec,debug 54a03727 e1121e18 2e92dd5f b1c093a9 0f17f17e 8fae9dee fdefffe2 d4d5f7ad 
08:01:25 ipsec,debug fdeac4b4 d48292fd b6a39417 
08:01:25 ipsec,debug begin. 
08:01:25 ipsec,debug seen nptype=8(hash) len=24 
08:01:25 ipsec,debug succeed. 
08:01:25 ipsec,debug HASH(3) validate: 
08:01:25 ipsec,debug 54a03727 e1121e18 2e92dd5f b1c093a9 0f17f17e 
08:01:25 ipsec,debug HASH with:  
08:01:25 ipsec,debug 00c096b4 779513cb a2659bbf 33493872 465d679e e3bd3420 dde445b1 8c467f9e 
08:01:25 ipsec,debug 30a17fa5 64fbbc7d 5822d618 26 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug HASH computed: 
08:01:25 ipsec,debug 54a03727 e1121e18 2e92dd5f b1c093a9 0f17f17e 
08:01:25 ipsec,debug === 
08:01:25 ipsec,debug KEYMAT compute with 
08:01:25 ipsec,debug 030514fc 889513cb a2659bbf 33493872 465d679e e3bd3420 dde445b1 8c467f9e 
08:01:25 ipsec,debug 30a17fa5 64fbbc7d 5822d618 26 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug encryption(aes-cbc) 
08:01:25 ipsec,debug hmac(sha1) 
08:01:25 ipsec,debug encklen=256 authklen=160 
08:01:25 ipsec,debug generating 640 bits of key (dupkeymat=4) 
08:01:25 ipsec,debug generating K1...K4 for KEYMAT. 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug d07cc6ef 25d35f78 5b9d9496 28cf4141 a80c3034 96ac6cf2 6bf883bd 53aa482c 
08:01:25 ipsec,debug e85735fe 77ff5822 a05340b1 10e1f4c8 1b8159fd 5aeb9f5b c5592075 09407f84 
08:01:25 ipsec,debug 9895edad b5d5dd59 32376826 7f8008e5 
08:01:25 ipsec,debug KEYMAT compute with 
08:01:25 ipsec,debug 030f0e72 079513cb a2659bbf 33493872 465d679e e3bd3420 dde445b1 8c467f9e 
08:01:25 ipsec,debug 30a17fa5 64fbbc7d 5822d618 26 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug encryption(aes-cbc) 
08:01:25 ipsec,debug hmac(sha1) 
08:01:25 ipsec,debug encklen=256 authklen=160 
08:01:25 ipsec,debug generating 640 bits of key (dupkeymat=4) 
08:01:25 ipsec,debug generating K1...K4 for KEYMAT. 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug hmac(hmac_sha1) 
08:01:25 ipsec,debug cfc9eb32 89be5f3b b11e5d14 a3c7a829 bc200e39 fc6de220 b83badaa 936cfb26 
08:01:25 ipsec,debug f87a0cf4 6fafe635 4e773796 782e5fce 7fbd6b31 120e8b33 199d1279 cfc8f04f 
08:01:25 ipsec,debug 3fe21546 449fc85a ab5cc00c 6dc15627 
08:01:25 ipsec,debug KEYMAT computed. 
08:01:25 ipsec,debug call pk_sendupdate 
08:01:25 ipsec,debug encryption(aes-cbc) 
08:01:25 ipsec,debug hmac(sha1) 
08:01:25 ipsec,debug call pfkey_send_update_nat 
08:01:25 ipsec IPsec-SA established: ESP/Transport PHONE-IP[13642]->ROUTER-IP[4500] spi=0x514fc88 
08:01:25 ipsec,debug pfkey update sent. 
08:01:25 ipsec,debug encryption(aes-cbc) 
08:01:25 ipsec,debug hmac(sha1) 
08:01:25 ipsec,debug call pfkey_send_add_nat 
08:01:25 ipsec IPsec-SA established: ESP/Transport ROUTER-IP[4500]->PHONE-IP[13642] spi=0xf0e7207 
08:01:25 ipsec,debug pfkey add sent. 
08:01:26 l2tp,debug,packet rcvd control message from PHONE-IP:49447 to ROUTER-IP:1701 
08:01:26 l2tp,debug,packet     tunnel-id=0, session-id=0, ns=0, nr=0 
08:01:26 l2tp,debug,packet     (M) Message-Type=SCCRQ 
08:01:26 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:01:26 l2tp,debug,packet     (M) Host-Name="anonymous" 
08:01:26 l2tp,debug,packet     (M) Framing-Capabilities=0x3 
08:01:26 l2tp,debug,packet     (M) Assigned-Tunnel-ID=60740 
08:01:26 l2tp,debug,packet     (M) Receive-Window-Size=1 
08:01:26 l2tp,info first L2TP UDP packet received from PHONE-IP 
08:01:26 l2tp,debug tunnel 176 entering state: wait-ctl-conn 
08:01:26 l2tp,debug,packet sent control message to PHONE-IP:49447 from ROUTER-IP:1701 
08:01:26 l2tp,debug,packet     tunnel-id=60740, session-id=0, ns=0, nr=1 
08:01:26 l2tp,debug,packet     (M) Message-Type=SCCRP 
08:01:26 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:01:26 l2tp,debug,packet     (M) Framing-Capabilities=0x1 
08:01:26 l2tp,debug,packet     (M) Bearer-Capabilities=0x0 
08:01:26 l2tp,debug,packet     Firmware-Revision=0x1 
08:01:26 l2tp,debug,packet     (M) Host-Name="ReichHub" 
08:01:26 l2tp,debug,packet     Vendor-Name="MikroTik" 
08:01:26 l2tp,debug,packet     (M) Assigned-Tunnel-ID=176 
08:01:26 l2tp,debug,packet     (M) Receive-Window-Size=4 
08:01:26 l2tp,debug,packet rcvd control message from PHONE-IP:49447 to ROUTER-IP:1701 
08:01:26 l2tp,debug,packet     tunnel-id=176, session-id=0, ns=1, nr=1 
08:01:26 l2tp,debug,packet     (M) Message-Type=SCCCN 
08:01:26 l2tp,debug tunnel 176 entering state: estabilished 
08:01:26 l2tp,debug,packet sent control message (ack) to PHONE-IP:49447 from ROUTER-IP:1701 
08:01:26 l2tp,debug,packet     tunnel-id=60740, session-id=0, ns=1, nr=2 
08:01:26 l2tp,debug,packet rcvd control message from PHONE-IP:49447 to ROUTER-IP:1701 
08:01:26 l2tp,debug,packet     tunnel-id=176, session-id=0, ns=2, nr=1 
08:01:26 l2tp,debug,packet     (M) Message-Type=ICRQ 
08:01:26 l2tp,debug,packet     (M) Assigned-Session-ID=55180 
08:01:26 l2tp,debug,packet     (M) Call-Serial-Number=1332303888 
08:01:26 l2tp,debug session 1 entering state: wait-connect 
08:01:26 l2tp,debug,packet sent control message to PHONE-IP:49447 from ROUTER-IP:1701 
08:01:26 l2tp,debug,packet     tunnel-id=60740, session-id=55180, ns=1, nr=3 
08:01:26 l2tp,debug,packet     (M) Message-Type=ICRP 
08:01:26 l2tp,debug,packet     (M) Assigned-Session-ID=1 
08:01:26 l2tp,debug,packet rcvd control message from PHONE-IP:49447 to ROUTER-IP:1701 
08:01:26 l2tp,debug,packet     tunnel-id=176, session-id=1, ns=3, nr=2 
08:01:26 l2tp,debug,packet     (M) Message-Type=ICCN 
08:01:26 l2tp,debug,packet     (M) Tx-Connect-Speed-BPS=100000000 
08:01:26 l2tp,debug,packet     (M) Framing-Type=0x3 
08:01:26 l2tp,debug session 1 entering state: established 
08:01:26 l2tp,debug,packet sent control message (ack) to PHONE-IP:49447 from ROUTER-IP:1701 
08:01:26 l2tp,debug,packet     tunnel-id=60740, session-id=0, ns=2, nr=4 
08:01:26 l2tp,ppp,debug <PHONE-IP>: LCP lowerup 
08:01:26 l2tp,ppp,debug <PHONE-IP>: LCP open 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd LCP ConfReq id=0x1 
08:01:26 l2tp,ppp,debug,packet    <mru 1400> 
08:01:26 l2tp,ppp,debug,packet    <asyncmap 0x0> 
08:01:26 l2tp,ppp,debug,packet    <magic 0x2d1ec4bc> 
08:01:26 l2tp,ppp,debug,packet    <pcomp> 
08:01:26 l2tp,ppp,debug,packet    <accomp> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent LCP ConfReq id=0x1 
08:01:26 l2tp,ppp,debug,packet    <mru 1450> 
08:01:26 l2tp,ppp,debug,packet    <magic 0x1352bb83> 
08:01:26 l2tp,ppp,debug,packet    <auth  mschap2> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent LCP ConfRej id=0x1 
08:01:26 l2tp,ppp,debug,packet    <asyncmap 0x0> 
08:01:26 l2tp,ppp,debug,packet    <pcomp> 
08:01:26 l2tp,ppp,debug,packet    <accomp> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd LCP ConfAck id=0x1 
08:01:26 l2tp,ppp,debug,packet    <mru 1450> 
08:01:26 l2tp,ppp,debug,packet    <magic 0x1352bb83> 
08:01:26 l2tp,ppp,debug,packet    <auth  mschap2> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd LCP ConfReq id=0x2 
08:01:26 l2tp,ppp,debug,packet    <mru 1400> 
08:01:26 l2tp,ppp,debug,packet    <magic 0x2d1ec4bc> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent LCP ConfAck id=0x2 
08:01:26 l2tp,ppp,debug,packet    <mru 1400> 
08:01:26 l2tp,ppp,debug,packet    <magic 0x2d1ec4bc> 
08:01:26 l2tp,ppp,debug <PHONE-IP>: LCP opened 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent CHAP Challenge id=0x1 
08:01:26 l2tp,ppp,debug,packet     <challenge len=16> 
08:01:26 l2tp,ppp,debug,packet     <name ReichHub> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd CHAP Response id=0x1 
08:01:26 l2tp,ppp,debug,packet     <response len=49> 
08:01:26 l2tp,ppp,debug,packet     <name reichnetwork\admin_bypass> 
08:01:26 l2tp,ppp,info,account admin_bypass logged in, 172.32.0.100 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent CHAP Success id=0x1 
08:01:26 l2tp,ppp,debug,packet     S=CF3D0D67B833994CC85408D69E29D6CB0C915772 
08:01:26 l2tp,ppp,info <l2tp-admin_bypass>: authenticated 
08:01:26 l2tp,ppp,debug <PHONE-IP>: IPCP lowerup 
08:01:26 l2tp,ppp,debug <PHONE-IP>: IPCP open 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent IPCP ConfReq id=0x1 
08:01:26 l2tp,ppp,debug,packet     <addr 172.32.0.1> 
08:01:26 l2tp,ppp,debug <PHONE-IP>: IPV6CP open 
08:01:26 l2tp,ppp,debug <PHONE-IP>: MPLSCP lowerup 
08:01:26 l2tp,ppp,debug <PHONE-IP>: MPLSCP open 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent MPLSCP ConfReq id=0x1 
08:01:26 l2tp,ppp,debug <PHONE-IP>: BCP open 
08:01:26 l2tp,ppp,debug <PHONE-IP>: CCP lowerup 
08:01:26 l2tp,ppp,debug <PHONE-IP>: CCP open 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd CCP ConfReq id=0x1 
08:01:26 l2tp,ppp,debug,packet     <deflate 15> 
08:01:26 l2tp,ppp,debug,packet     <deflate (old) 15> 
08:01:26 l2tp,ppp,debug,packet     <0x15 03 2f> 
08:01:26 l2tp,ppp,debug <PHONE-IP>: received unsupported protocol 0x80fd 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent LCP ProtRej id=0x2 
08:01:26 l2tp,ppp,debug,packet      80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03... 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd IPCP ConfReq id=0x1 
08:01:26 l2tp,ppp,debug,packet     <addr 0.0.0.0> 
08:01:26 l2tp,ppp,debug,packet     <comp VJ f 1> 
08:01:26 l2tp,ppp,debug,packet     <ms-dns 0.0.0.0> 
08:01:26 l2tp,ppp,debug,packet     <ms-dns 0.0.0.0> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent IPCP ConfRej id=0x1 
08:01:26 l2tp,ppp,debug,packet     <comp VJ f 1> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd LCP ProtRej id=0x3 
08:01:26 l2tp,ppp,debug,packet      82 81 01 01 00 04 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd IPCP ConfAck id=0x1 
08:01:26 l2tp,ppp,debug,packet     <addr 172.32.0.1> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd IPCP ConfReq id=0x2 
08:01:26 l2tp,ppp,debug,packet     <addr 0.0.0.0> 
08:01:26 l2tp,ppp,debug,packet     <ms-dns 0.0.0.0> 
08:01:26 l2tp,ppp,debug,packet     <ms-dns 0.0.0.0> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent IPCP ConfNak id=0x2 
08:01:26 l2tp,ppp,debug,packet     <addr 172.32.0.100> 
08:01:26 l2tp,ppp,debug,packet     <ms-dns 172.32.0.1> 
08:01:26 l2tp,ppp,debug,packet     <ms-dns 10.0.0.3> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd IPCP ConfReq id=0x3 
08:01:26 l2tp,ppp,debug,packet     <addr 172.32.0.100> 
08:01:26 l2tp,ppp,debug,packet     <ms-dns 172.32.0.1> 
08:01:26 l2tp,ppp,debug,packet     <ms-dns 10.0.0.3> 
08:01:26 l2tp,ppp,debug,packet  <PHONE-IP>: sent IPCP ConfAck id=0x3 
08:01:26 l2tp,ppp,debug,packet     <addr 172.32.0.100> 
08:01:26 l2tp,ppp,debug,packet     <ms-dns 172.32.0.1> 
08:01:26 l2tp,ppp,debug,packet     <ms-dns 10.0.0.3> 
08:01:26 l2tp,ppp,debug <PHONE-IP>: IPCP opened 
08:01:26 l2tp,ppp,info <l2tp-admin_bypass>: connected 
08:01:27 l2tp,debug,packet sent control message to 159.121.202.141:1701 from ROUTER-IP:1701 
08:01:27 l2tp,debug,packet     tunnel-id=19, session-id=0, ns=2, nr=4 
08:01:27 l2tp,debug,packet     (M) Message-Type=HELLO 
08:01:27 l2tp,debug,packet rcvd control message (ack) from 159.121.202.141:1701 to ROUTER-IP:1701 
08:01:27 l2tp,debug,packet     tunnel-id=175, session-id=0, ns=4, nr=3 
08:01:35 ipsec,debug KA: ROUTER-IP[4500]->159.121.202.141[59096] 
08:01:35 ipsec,debug 1 times of 1 bytes message will be sent to 159.121.202.141[59096] 
08:01:35 ipsec,debug,packet ff 
08:01:35 ipsec,debug KA: ROUTER-IP[4500]->PHONE-IP[13642] 
08:01:35 ipsec,debug 1 times of 1 bytes message will be sent to PHONE-IP[13642] 
08:01:35 ipsec,debug,packet ff 
08:01:41 ipsec,debug ===== received 92 bytes from 71.59.152.62[500] to ROUTER-IP[500] 
08:01:41 ipsec,debug,packet fa15d9d5 aab98a8f ddbd5468 175cd664 08100501 eaaa04d6 0000005c 47bc52da 
08:01:41 ipsec,debug,packet b1451f3c 24003d3f a459becc 11cb9397 0924179b 56c0cfff 3f03b1f3 88badb96 
08:01:41 ipsec,debug,packet 38ea4448 dfcac53b 0c9e352c c8fffe64 bdb4b6c3 1731e567 5b246bd7 
08:01:41 ipsec,debug receive Information. 
08:01:41 ipsec,debug compute IV for phase2 
08:01:41 ipsec,debug phase1 last IV: 
08:01:41 ipsec,debug e17e326b a57d05eb eaaa04d6 
08:01:41 ipsec,debug hash(sha1) 
08:01:41 ipsec,debug encryption(3des) 
08:01:41 ipsec,debug phase2 IV computed: 
08:01:41 ipsec,debug 053ec483 d99725e0 
08:01:41 ipsec,debug encryption(3des) 
08:01:41 ipsec,debug IV was saved for next processing: 
08:01:41 ipsec,debug 1731e567 5b246bd7 
08:01:41 ipsec,debug encryption(3des) 
08:01:41 ipsec,debug with key: 
08:01:41 ipsec,debug ecf57f84 35edc707 e5062848 3227df94 fd846a40 99fdd8ba 
08:01:41 ipsec,debug decrypted payload by IV: 
08:01:41 ipsec,debug 053ec483 d99725e0 
08:01:41 ipsec,debug decrypted payload, but not trimed. 
08:01:41 ipsec,debug 0b000018 e54be462 20edf66f ab13103a 39025c55 817dcafe 00000020 00000001 
08:01:41 ipsec,debug 01108d28 fa15d9d5 aab98a8f ddbd5468 175cd664 000003be d8a4d0d0 c4f5b107 
08:01:41 ipsec,debug padding len=8 
08:01:41 ipsec,debug skip to trim padding. 
08:01:41 ipsec,debug decrypted. 
08:01:41 ipsec,debug fa15d9d5 aab98a8f ddbd5468 175cd664 08100501 eaaa04d6 0000005c 0b000018 
08:01:41 ipsec,debug e54be462 20edf66f ab13103a 39025c55 817dcafe 00000020 00000001 01108d28 
08:01:41 ipsec,debug fa15d9d5 aab98a8f ddbd5468 175cd664 000003be d8a4d0d0 c4f5b107 
08:01:41 ipsec,debug HASH with: 
08:01:41 ipsec,debug eaaa04d6 00000020 00000001 01108d28 fa15d9d5 aab98a8f ddbd5468 175cd664 
08:01:41 ipsec,debug 000003be 
08:01:41 ipsec,debug hmac(hmac_sha1) 
08:01:41 ipsec,debug HASH computed: 
08:01:41 ipsec,debug e54be462 20edf66f ab13103a 39025c55 817dcafe 
08:01:41 ipsec,debug hash validated. 
08:01:41 ipsec,debug begin. 
08:01:41 ipsec,debug seen nptype=8(hash) len=24 
08:01:41 ipsec,debug seen nptype=11(notify) len=32 
08:01:41 ipsec,debug succeed. 
08:01:41 ipsec,debug 71.59.152.62 notify: R_U_THERE 
08:01:41 ipsec,debug 71.59.152.62 DPD R-U-There received 
08:01:41 ipsec,debug compute IV for phase2 
08:01:41 ipsec,debug phase1 last IV: 
08:01:41 ipsec,debug e17e326b a57d05eb fd9cbd55 
08:01:41 ipsec,debug hash(sha1) 
08:01:41 ipsec,debug encryption(3des) 
08:01:41 ipsec,debug phase2 IV computed: 
08:01:41 ipsec,debug 7758c9a3 39d6263b 
08:01:41 ipsec,debug HASH with: 
08:01:41 ipsec,debug fd9cbd55 00000020 00000001 01108d29 fa15d9d5 aab98a8f ddbd5468 175cd664 
08:01:41 ipsec,debug 000003be 
08:01:41 ipsec,debug hmac(hmac_sha1) 
08:01:41 ipsec,debug HASH computed: 
08:01:41 ipsec,debug ce042bb6 a79a65bf 1bb9800b 05dedf91 c1da7eca 
08:01:41 ipsec,debug begin encryption. 
08:01:41 ipsec,debug encryption(3des) 
08:01:41 ipsec,debug pad length = 8 
08:01:41 ipsec,debug 0b000018 ce042bb6 a79a65bf 1bb9800b 05dedf91 c1da7eca 00000020 00000001 
08:01:41 ipsec,debug 01108d29 fa15d9d5 aab98a8f ddbd5468 175cd664 000003be c9e3faf0 f7f5c707 
08:01:41 ipsec,debug encryption(3des) 
08:01:41 ipsec,debug with key: 
08:01:41 ipsec,debug ecf57f84 35edc707 e5062848 3227df94 fd846a40 99fdd8ba 
08:01:41 ipsec,debug encrypted payload by IV: 
08:01:41 ipsec,debug 7758c9a3 39d6263b 
08:01:41 ipsec,debug save IV for next: 
08:01:41 ipsec,debug b2fc3eee 1c58ee69 
08:01:41 ipsec,debug encrypted. 
08:01:41 ipsec,debug 92 bytes from ROUTER-IP[500] to 71.59.152.62[500] 
08:01:41 ipsec,debug 1 times of 92 bytes message will be sent to 71.59.152.62[500] 
08:01:41 ipsec,debug,packet fa15d9d5 aab98a8f ddbd5468 175cd664 08100501 fd9cbd55 0000005c 23a1475d 
08:01:41 ipsec,debug,packet 006b113b 2b098591 c9ecb924 747d544a 589e6065 f1a9981b b02fd86b 7cfe714c 
08:01:41 ipsec,debug,packet e7357eba c479b078 8e6b1ae6 7e52353d 0e2ce2dd b2fc3eee 1c58ee69 
08:01:41 ipsec,debug sendto Information notify. 
08:01:41 ipsec,debug received a valid R-U-THERE, ACK sent 
08:01:55 ipsec,debug KA: ROUTER-IP[4500]->159.121.202.141[59096] 
08:01:55 ipsec,debug 1 times of 1 bytes message will be sent to 159.121.202.141[59096] 
08:01:55 ipsec,debug,packet ff 
08:01:55 ipsec,debug KA: ROUTER-IP[4500]->PHONE-IP[13642] 
08:01:55 ipsec,debug 1 times of 1 bytes message will be sent to PHONE-IP[13642] 
08:01:55 ipsec,debug,packet ff 
08:02:06 ipsec,debug ===== received 92 bytes from 71.59.152.62[500] to ROUTER-IP[500] 
08:02:06 ipsec,debug,packet 1be0021f 5161e822 72fb31f7 96fb8b12 08100501 b07bb06f 0000005c 7b6aab43 
08:02:06 ipsec,debug,packet 32f19d83 b4447904 1168a249 b5fe3108 5c1bd53c 148bad81 8f44a97f 9e80bc55 
08:02:06 ipsec,debug,packet 0e1c911e e571ea8c 54df16a0 c9db9872 18c3742c 5e13f1a2 a851ea84 
08:02:06 ipsec,debug receive Information. 
08:02:06 ipsec,debug compute IV for phase2 
08:02:06 ipsec,debug phase1 last IV: 
08:02:06 ipsec,debug 828aa727 e3b36deb b07bb06f 
08:02:06 ipsec,debug hash(sha1) 
08:02:06 ipsec,debug encryption(3des) 
08:02:06 ipsec,debug phase2 IV computed: 
08:02:06 ipsec,debug 7845ea6c 48b64784 
08:02:06 ipsec,debug encryption(3des) 
08:02:06 ipsec,debug IV was saved for next processing: 
08:02:06 ipsec,debug 5e13f1a2 a851ea84 
08:02:06 ipsec,debug encryption(3des) 
08:02:06 ipsec,debug with key: 
08:02:06 ipsec,debug ff6e0cf6 0ff589db 726ff018 f389f2db 012da640 4e54ae9a 
08:02:06 ipsec,debug decrypted payload by IV: 
08:02:06 ipsec,debug 7845ea6c 48b64784 
08:02:06 ipsec,debug decrypted payload, but not trimed. 
08:02:06 ipsec,debug 0b000018 29aad142 16619fe1 d692fae4 cc0d196d 40405bb4 00000020 00000001 
08:02:06 ipsec,debug 01108d28 1be0021f 5161e822 72fb31f7 96fb8b12 00001222 b699d9fe a694c907 
08:02:06 ipsec,debug padding len=8 
08:02:06 ipsec,debug skip to trim padding. 
08:02:06 ipsec,debug decrypted. 
08:02:06 ipsec,debug 1be0021f 5161e822 72fb31f7 96fb8b12 08100501 b07bb06f 0000005c 0b000018 
08:02:06 ipsec,debug 29aad142 16619fe1 d692fae4 cc0d196d 40405bb4 00000020 00000001 01108d28 
08:02:06 ipsec,debug 1be0021f 5161e822 72fb31f7 96fb8b12 00001222 b699d9fe a694c907 
08:02:06 ipsec,debug HASH with: 
08:02:06 ipsec,debug b07bb06f 00000020 00000001 01108d28 1be0021f 5161e822 72fb31f7 96fb8b12 
08:02:06 ipsec,debug 00001222 
08:02:06 ipsec,debug hmac(hmac_sha1) 
08:02:06 ipsec,debug HASH computed: 
08:02:06 ipsec,debug 29aad142 16619fe1 d692fae4 cc0d196d 40405bb4 
08:02:06 ipsec,debug hash validated. 
08:02:06 ipsec,debug begin. 
08:02:06 ipsec,debug seen nptype=8(hash) len=24 
08:02:06 ipsec,debug seen nptype=11(notify) len=32 
08:02:06 ipsec,debug succeed. 
08:02:06 ipsec,debug 71.59.152.62 notify: R_U_THERE 
08:02:06 ipsec,debug 71.59.152.62 DPD R-U-There received 
08:02:06 ipsec,debug compute IV for phase2 
08:02:06 ipsec,debug phase1 last IV: 
08:02:06 ipsec,debug 828aa727 e3b36deb c776c92b 
08:02:06 ipsec,debug hash(sha1) 
08:02:06 ipsec,debug encryption(3des) 
08:02:06 ipsec,debug phase2 IV computed: 
08:02:06 ipsec,debug 2e228742 b0d316fc 
08:02:06 ipsec,debug HASH with: 
08:02:06 ipsec,debug c776c92b 00000020 00000001 01108d29 1be0021f 5161e822 72fb31f7 96fb8b12 
08:02:06 ipsec,debug 00001222 
08:02:06 ipsec,debug hmac(hmac_sha1) 
08:02:06 ipsec,debug HASH computed: 
08:02:06 ipsec,debug b69e80fd 6df93c83 adf7077d 26b37e28 772e71aa 
08:02:06 ipsec,debug begin encryption. 
08:02:06 ipsec,debug encryption(3des) 
08:02:06 ipsec,debug pad length = 8 
08:02:06 ipsec,debug 0b000018 b69e80fd 6df93c83 adf7077d 26b37e28 772e71aa 00000020 00000001 
08:02:06 ipsec,debug 01108d29 1be0021f 5161e822 72fb31f7 96fb8b12 00001222 dac8b5e1 fddf8107 
08:02:06 ipsec,debug encryption(3des) 
08:02:06 ipsec,debug with key: 
08:02:06 ipsec,debug ff6e0cf6 0ff589db 726ff018 f389f2db 012da640 4e54ae9a 
08:02:06 ipsec,debug encrypted payload by IV: 
08:02:06 ipsec,debug 2e228742 b0d316fc 
08:02:06 ipsec,debug save IV for next: 
08:02:06 ipsec,debug 7c6192f6 a7af531c 
08:02:06 ipsec,debug encrypted. 
08:02:06 ipsec,debug 92 bytes from ROUTER-IP[500] to 71.59.152.62[500] 
08:02:06 ipsec,debug 1 times of 92 bytes message will be sent to 71.59.152.62[500] 
08:02:06 ipsec,debug,packet 1be0021f 5161e822 72fb31f7 96fb8b12 08100501 c776c92b 0000005c 5bd218f9 
08:02:06 ipsec,debug,packet 765cd374 cf92d75f bd5ec583 7cdf3b35 f155d910 fde00901 2285b6b9 ec8c7322 
08:02:06 ipsec,debug,packet 560f39bf bee626e3 699c1721 e0c8d764 b6cacb72 7c6192f6 a7af531c 
08:02:06 ipsec,debug sendto Information notify. 
08:02:06 ipsec,debug received a valid R-U-THERE, ACK sent 
08:02:07 l2tp,debug,packet rcvd control message from 146.88.240.4:1701 to ROUTER-IP:1701 
08:02:07 l2tp,debug,packet     tunnel-id=0, session-id=0, ns=0, nr=0 
08:02:07 l2tp,debug,packet     (M) Message-Type=SCCRQ 
08:02:07 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:02:07 l2tp,debug,packet     (M) Host-Name="2.am" 
08:02:07 l2tp,debug,packet     (M) Framing-Capabilities=0x1 
08:02:07 l2tp,debug,packet     (M) Assigned-Tunnel-ID=35 
08:02:07 l2tp,info first L2TP UDP packet received from 146.88.240.4 
08:02:07 l2tp,debug tunnel 177 entering state: wait-ctl-conn 
08:02:07 l2tp,debug,packet sent control message to 146.88.240.4:1701 from ROUTER-IP:1701 
08:02:07 l2tp,debug,packet     tunnel-id=35, session-id=0, ns=0, nr=1 
08:02:07 l2tp,debug,packet     (M) Message-Type=SCCRP 
08:02:07 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:02:07 l2tp,debug,packet     (M) Framing-Capabilities=0x1 
08:02:07 l2tp,debug,packet     (M) Bearer-Capabilities=0x0 
08:02:07 l2tp,debug,packet     Firmware-Revision=0x1 
08:02:07 l2tp,debug,packet     (M) Host-Name="ReichHub" 
08:02:07 l2tp,debug,packet     Vendor-Name="MikroTik" 
08:02:07 l2tp,debug,packet     (M) Assigned-Tunnel-ID=177 
08:02:07 l2tp,debug,packet     (M) Receive-Window-Size=4 
08:02:08 l2tp,debug,packet rcvd control message from 75.107.121.2:1701 to ROUTER-IP:1701 
08:02:08 l2tp,debug,packet     tunnel-id=143, session-id=0, ns=3273, nr=3271 
08:02:08 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:08 l2tp,debug,packet sent control message (ack) to 75.107.121.2:1701 from ROUTER-IP:1701 
08:02:08 l2tp,debug,packet     tunnel-id=12, session-id=0, ns=3271, nr=3274 
08:02:08 l2tp,debug,packet sent control message to 75.107.121.2:1701 from ROUTER-IP:1701 
08:02:08 l2tp,debug,packet     tunnel-id=12, session-id=0, ns=3271, nr=3274 
08:02:08 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:08 l2tp,debug,packet sent control message to 146.88.240.4:1701 from ROUTER-IP:1701 
08:02:08 l2tp,debug,packet     tunnel-id=35, session-id=0, ns=0, nr=1 
08:02:08 l2tp,debug,packet     (M) Message-Type=SCCRP 
08:02:08 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:02:08 l2tp,debug,packet     (M) Framing-Capabilities=0x1 
08:02:08 l2tp,debug,packet     (M) Bearer-Capabilities=0x0 
08:02:08 l2tp,debug,packet     Firmware-Revision=0x1 
08:02:08 l2tp,debug,packet     (M) Host-Name="ReichHub" 
08:02:08 l2tp,debug,packet     Vendor-Name="MikroTik" 
08:02:08 l2tp,debug,packet     (M) Assigned-Tunnel-ID=177 
08:02:08 l2tp,debug,packet     (M) Receive-Window-Size=4 
08:02:08 l2tp,debug,packet rcvd control message (ack) from 75.107.121.2:1701 to ROUTER-IP:1701 
08:02:08 l2tp,debug,packet     tunnel-id=143, session-id=0, ns=3274, nr=3272 
08:02:09 l2tp,debug,packet sent control message to 146.88.240.4:1701 from ROUTER-IP:1701 
08:02:09 l2tp,debug,packet     tunnel-id=35, session-id=0, ns=0, nr=1 
08:02:09 l2tp,debug,packet     (M) Message-Type=SCCRP 
08:02:09 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:02:09 l2tp,debug,packet     (M) Framing-Capabilities=0x1 
08:02:09 l2tp,debug,packet     (M) Bearer-Capabilities=0x0 
08:02:09 l2tp,debug,packet     Firmware-Revision=0x1 
08:02:09 l2tp,debug,packet     (M) Host-Name="ReichHub" 
08:02:09 l2tp,debug,packet     Vendor-Name="MikroTik" 
08:02:09 l2tp,debug,packet     (M) Assigned-Tunnel-ID=177 
08:02:09 l2tp,debug,packet     (M) Receive-Window-Size=4 
08:02:11 l2tp,debug,packet sent control message to 146.88.240.4:1701 from ROUTER-IP:1701 
08:02:11 l2tp,debug,packet     tunnel-id=35, session-id=0, ns=0, nr=1 
08:02:11 l2tp,debug,packet     (M) Message-Type=SCCRP 
08:02:11 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:02:11 l2tp,debug,packet     (M) Framing-Capabilities=0x1 
08:02:11 l2tp,debug,packet     (M) Bearer-Capabilities=0x0 
08:02:11 l2tp,debug,packet     Firmware-Revision=0x1 
08:02:11 l2tp,debug,packet     (M) Host-Name="ReichHub" 
08:02:11 l2tp,debug,packet     Vendor-Name="MikroTik" 
08:02:11 l2tp,debug,packet     (M) Assigned-Tunnel-ID=177 
08:02:11 l2tp,debug,packet     (M) Receive-Window-Size=4 
08:02:13 l2tp,debug,packet rcvd control message from 71.59.152.62:1701 to ROUTER-IP:1701 
08:02:13 l2tp,debug,packet     tunnel-id=170, session-id=0, ns=929, nr=927 
08:02:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:13 l2tp,debug,packet sent control message (ack) to 71.59.152.62:1701 from ROUTER-IP:1701 
08:02:13 l2tp,debug,packet     tunnel-id=53, session-id=0, ns=927, nr=930 
08:02:13 l2tp,debug,packet sent control message to 71.59.152.62:1701 from ROUTER-IP:1701 
08:02:13 l2tp,debug,packet     tunnel-id=53, session-id=0, ns=927, nr=930 
08:02:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:13 l2tp,debug,packet rcvd control message (ack) from 71.59.152.62:1701 to ROUTER-IP:1701 
08:02:13 l2tp,debug,packet     tunnel-id=170, session-id=0, ns=930, nr=928 
08:02:15 ipsec,debug KA: ROUTER-IP[4500]->159.121.202.141[59096] 
08:02:15 ipsec,debug 1 times of 1 bytes message will be sent to 159.121.202.141[59096] 
08:02:15 ipsec,debug,packet ff 
08:02:15 ipsec,debug KA: ROUTER-IP[4500]->PHONE-IP[13642] 
08:02:15 ipsec,debug 1 times of 1 bytes message will be sent to PHONE-IP[13642] 
08:02:15 ipsec,debug,packet ff 
08:02:15 l2tp,debug,packet sent control message to 146.88.240.4:1701 from ROUTER-IP:1701 
08:02:15 l2tp,debug,packet     tunnel-id=35, session-id=0, ns=0, nr=1 
08:02:15 l2tp,debug,packet     (M) Message-Type=SCCRP 
08:02:15 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:02:15 l2tp,debug,packet     (M) Framing-Capabilities=0x1 
08:02:15 l2tp,debug,packet     (M) Bearer-Capabilities=0x0 
08:02:15 l2tp,debug,packet     Firmware-Revision=0x1 
08:02:15 l2tp,debug,packet     (M) Host-Name="ReichHub" 
08:02:15 l2tp,debug,packet     Vendor-Name="MikroTik" 
08:02:15 l2tp,debug,packet     (M) Assigned-Tunnel-ID=177 
08:02:15 l2tp,debug,packet     (M) Receive-Window-Size=4 
08:02:23 l2tp,debug,packet sent control message to 146.88.240.4:1701 from ROUTER-IP:1701 
08:02:23 l2tp,debug,packet     tunnel-id=35, session-id=0, ns=0, nr=1 
08:02:23 l2tp,debug,packet     (M) Message-Type=SCCRP 
08:02:23 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:02:23 l2tp,debug,packet     (M) Framing-Capabilities=0x1 
08:02:23 l2tp,debug,packet     (M) Bearer-Capabilities=0x0 
08:02:23 l2tp,debug,packet     Firmware-Revision=0x1 
08:02:23 l2tp,debug,packet     (M) Host-Name="ReichHub" 
08:02:23 l2tp,debug,packet     Vendor-Name="MikroTik" 
08:02:23 l2tp,debug,packet     (M) Assigned-Tunnel-ID=177 
08:02:23 l2tp,debug,packet     (M) Receive-Window-Size=4 
08:02:26 l2tp,debug,packet sent control message to PHONE-IP:49447 from ROUTER-IP:1701 
08:02:26 l2tp,debug,packet     tunnel-id=60740, session-id=0, ns=2, nr=4 
08:02:26 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:27 l2tp,debug,packet sent control message to PHONE-IP:49447 from ROUTER-IP:1701 
08:02:27 l2tp,debug,packet     tunnel-id=60740, session-id=0, ns=2, nr=4 
08:02:27 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:27 l2tp,debug,packet sent control message to 159.121.202.141:1701 from ROUTER-IP:1701 
08:02:27 l2tp,debug,packet     tunnel-id=19, session-id=0, ns=3, nr=4 
08:02:27 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:27 l2tp,debug,packet rcvd control message (ack) from 159.121.202.141:1701 to ROUTER-IP:1701 
08:02:27 l2tp,debug,packet     tunnel-id=175, session-id=0, ns=4, nr=4 
08:02:28 l2tp,debug,packet sent control message to PHONE-IP:49447 from ROUTER-IP:1701 
08:02:28 l2tp,debug,packet     tunnel-id=60740, session-id=0, ns=2, nr=4 
08:02:28 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:30 l2tp,debug,packet sent control message to PHONE-IP:49447 from ROUTER-IP:1701 
08:02:30 l2tp,debug,packet     tunnel-id=60740, session-id=0, ns=2, nr=4 
08:02:30 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:31 l2tp,debug tunnel 177 received no replies, disconnecting 
08:02:31 l2tp,debug tunnel 177 entering state: dead 
08:02:34 l2tp,debug,packet sent control message to PHONE-IP:49447 from ROUTER-IP:1701 
08:02:34 l2tp,debug,packet     tunnel-id=60740, session-id=0, ns=2, nr=4 
08:02:34 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:35 ipsec,debug KA: ROUTER-IP[4500]->159.121.202.141[59096] 
08:02:35 ipsec,debug 1 times of 1 bytes message will be sent to 159.121.202.141[59096] 
08:02:35 ipsec,debug,packet ff 
08:02:35 ipsec,debug KA: ROUTER-IP[4500]->PHONE-IP[13642] 
08:02:35 ipsec,debug 1 times of 1 bytes message will be sent to PHONE-IP[13642] 
08:02:35 ipsec,debug,packet ff 
08:02:42 l2tp,debug,packet sent control message to PHONE-IP:49447 from ROUTER-IP:1701 
08:02:42 l2tp,debug,packet     tunnel-id=60740, session-id=0, ns=2, nr=4 
08:02:42 l2tp,debug,packet     (M) Message-Type=HELLO 
08:02:50 l2tp,debug tunnel 176 received no replies, disconnecting 
08:02:50 l2tp,debug tunnel 176 entering state: dead 
08:02:50 l2tp,debug session 1 entering state: dead 
08:02:50 l2tp,ppp,debug <PHONE-IP>: LCP lowerdown 
08:02:50 l2tp,ppp,debug <PHONE-IP>: LCP closed 
08:02:50 l2tp,ppp,debug <PHONE-IP>: CCP lowerdown 
08:02:50 l2tp,ppp,debug <PHONE-IP>: BCP lowerdown 
08:02:50 l2tp,ppp,debug <PHONE-IP>: BCP down event in starting state 
08:02:50 l2tp,ppp,debug <PHONE-IP>: IPCP lowerdown 
08:02:50 l2tp,ppp,debug <PHONE-IP>: IPCP closed 
08:02:50 l2tp,ppp,debug <PHONE-IP>: IPV6CP lowerdown 
08:02:50 l2tp,ppp,debug <PHONE-IP>: IPV6CP down event in starting state 
08:02:50 l2tp,ppp,debug <PHONE-IP>: MPLSCP lowerdown 
08:02:50 l2tp,ppp,debug <PHONE-IP>: CCP close 
08:02:50 l2tp,ppp,debug <PHONE-IP>: BCP close 
08:02:50 l2tp,ppp,debug <PHONE-IP>: IPCP close 
08:02:50 l2tp,ppp,debug <PHONE-IP>: IPV6CP close 
08:02:50 l2tp,ppp,debug <PHONE-IP>: MPLSCP close 
08:02:50 l2tp,ppp,info <l2tp-admin_bypass>: terminating... - hungup 
08:02:50 l2tp,ppp,debug <PHONE-IP>: LCP lowerdown 
08:02:50 l2tp,ppp,debug <PHONE-IP>: LCP down event in starting state 
08:02:50 l2tp,ppp,info,account admin_bypass logged out, 84 4276790 250538466 94819 180264 
08:02:50 l2tp,ppp,info <l2tp-admin_bypass>: disconnected 
08:02:55 ipsec,debug KA: ROUTER-IP[4500]->159.121.202.141[59096] 
08:02:55 ipsec,debug 1 times of 1 bytes message will be sent to 159.121.202.141[59096] 
08:02:55 ipsec,debug,packet ff 
08:02:55 ipsec,debug KA: ROUTER-IP[4500]->PHONE-IP[13642] 
08:02:55 ipsec,debug 1 times of 1 bytes message will be sent to PHONE-IP[13642] 
08:02:55 ipsec,debug,packet ff 
08:03:08 l2tp,debug,packet rcvd control message from 75.107.121.2:1701 to ROUTER-IP:1701 
08:03:08 l2tp,debug,packet     tunnel-id=143, session-id=0, ns=3274, nr=3272 
08:03:08 l2tp,debug,packet     (M) Message-Type=HELLO 
08:03:08 l2tp,debug,packet sent control message (ack) to 75.107.121.2:1701 from ROUTER-IP:1701 
08:03:08 l2tp,debug,packet     tunnel-id=12, session-id=0, ns=3272, nr=3275 
08:03:08 l2tp,debug,packet sent control message to 75.107.121.2:1701 from ROUTER-IP:1701 
08:03:08 l2tp,debug,packet     tunnel-id=12, session-id=0, ns=3272, nr=3275 
08:03:08 l2tp,debug,packet     (M) Message-Type=HELLO 
08:03:09 l2tp,debug,packet rcvd control message (ack) from 75.107.121.2:1701 to ROUTER-IP:1701 
08:03:09 l2tp,debug,packet     tunnel-id=143, session-id=0, ns=3275, nr=3273 
08:03:13 l2tp,debug,packet rcvd control message from 71.59.152.62:1701 to ROUTER-IP:1701 
08:03:13 l2tp,debug,packet     tunnel-id=170, session-id=0, ns=930, nr=928 
08:03:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:03:13 l2tp,debug,packet sent control message (ack) to 71.59.152.62:1701 from ROUTER-IP:1701 
08:03:13 l2tp,debug,packet     tunnel-id=53, session-id=0, ns=928, nr=931 
08:03:13 l2tp,debug,packet sent control message to 71.59.152.62:1701 from ROUTER-IP:1701 
08:03:13 l2tp,debug,packet     tunnel-id=53, session-id=0, ns=928, nr=931 
08:03:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:03:13 l2tp,debug,packet rcvd control message (ack) from 71.59.152.62:1701 to ROUTER-IP:1701 
08:03:13 l2tp,debug,packet     tunnel-id=170, session-id=0, ns=931, nr=929 
08:03:15 ipsec,debug KA: ROUTER-IP[4500]->159.121.202.141[59096] 
08:03:15 ipsec,debug 1 times of 1 bytes message will be sent to 159.121.202.141[59096] 
08:03:15 ipsec,debug,packet ff 
08:03:15 ipsec,debug KA: ROUTER-IP[4500]->PHONE-IP[13642] 
08:03:15 ipsec,debug 1 times of 1 bytes message will be sent to PHONE-IP[13642] 
08:03:15 ipsec,debug,packet ff 
08:03:16 ipsec,debug ===== received 92 bytes from 75.107.121.2[500] to ROUTER-IP[500] 
08:03:16 ipsec,debug,packet e9b2f4eb 7775cd8c d54e5807 8d292f9b 08100501 de0f3776 0000005c 19fb18fb 
08:03:16 ipsec,debug,packet b223ef02 aff9b0dc 44b37d96 17edade6 42349dea e48f071e 75f17e2c 817b9c97 
08:03:16 ipsec,debug,packet df61c19f 1c40e5a8 b4eba5be da8ce1db 38336af8 6ad5ebfd 8ddd5f20 
08:03:16 ipsec,debug receive Information. 
08:03:16 ipsec,debug compute IV for phase2 
08:03:16 ipsec,debug phase1 last IV: 
08:03:16 ipsec,debug d84f5c4e a52b5298 de0f3776 
08:03:16 ipsec,debug hash(sha1) 
08:03:16 ipsec,debug encryption(3des) 
08:03:16 ipsec,debug phase2 IV computed: 
08:03:16 ipsec,debug 20e6cc84 f381cd1a 
08:03:16 ipsec,debug encryption(3des) 
08:03:16 ipsec,debug IV was saved for next processing: 
08:03:16 ipsec,debug 6ad5ebfd 8ddd5f20 
08:03:16 ipsec,debug encryption(3des) 
08:03:16 ipsec,debug with key: 
08:03:16 ipsec,debug 34e76bf3 bdb02b64 47a87b8e e6f5d824 bc49f3e4 3c92dcc9 
08:03:16 ipsec,debug decrypted payload by IV: 
08:03:16 ipsec,debug 20e6cc84 f381cd1a 
08:03:16 ipsec,debug decrypted payload, but not trimed. 
08:03:16 ipsec,debug 0b000018 29c71c42 62bad230 9d634b77 72eaf72e e01d5b25 00000020 00000001 
08:03:16 ipsec,debug 01108d28 e9b2f4eb 7775cd8c d54e5807 8d292f9b 0000109a a3fe82bc cbf18907 
08:03:16 ipsec,debug padding len=8 
08:03:16 ipsec,debug skip to trim padding. 
08:03:16 ipsec,debug decrypted. 
08:03:16 ipsec,debug e9b2f4eb 7775cd8c d54e5807 8d292f9b 08100501 de0f3776 0000005c 0b000018 
08:03:16 ipsec,debug 29c71c42 62bad230 9d634b77 72eaf72e e01d5b25 00000020 00000001 01108d28 
08:03:16 ipsec,debug e9b2f4eb 7775cd8c d54e5807 8d292f9b 0000109a a3fe82bc cbf18907 
08:03:16 ipsec,debug HASH with: 
08:03:16 ipsec,debug de0f3776 00000020 00000001 01108d28 e9b2f4eb 7775cd8c d54e5807 8d292f9b 
08:03:16 ipsec,debug 0000109a 
08:03:16 ipsec,debug hmac(hmac_sha1) 
08:03:16 ipsec,debug HASH computed: 
08:03:16 ipsec,debug 29c71c42 62bad230 9d634b77 72eaf72e e01d5b25 
08:03:16 ipsec,debug hash validated. 
08:03:16 ipsec,debug begin. 
08:03:16 ipsec,debug seen nptype=8(hash) len=24 
08:03:16 ipsec,debug seen nptype=11(notify) len=32 
08:03:16 ipsec,debug succeed. 
08:03:16 ipsec,debug 75.107.121.2 notify: R_U_THERE 
08:03:16 ipsec,debug 75.107.121.2 DPD R-U-There received 
08:03:16 ipsec,debug compute IV for phase2 
08:03:16 ipsec,debug phase1 last IV: 
08:03:16 ipsec,debug d84f5c4e a52b5298 9a12d2e1 
08:03:16 ipsec,debug hash(sha1) 
08:03:16 ipsec,debug encryption(3des) 
08:03:16 ipsec,debug phase2 IV computed: 
08:03:16 ipsec,debug 53447662 5db8e01f 
08:03:16 ipsec,debug HASH with: 
08:03:16 ipsec,debug 9a12d2e1 00000020 00000001 01108d29 e9b2f4eb 7775cd8c d54e5807 8d292f9b 
08:03:16 ipsec,debug 0000109a 
08:03:16 ipsec,debug hmac(hmac_sha1) 
08:03:16 ipsec,debug HASH computed: 
08:03:16 ipsec,debug ae09f660 7f8824e8 31580541 4c181edb 03da9e47 
08:03:16 ipsec,debug begin encryption. 
08:03:16 ipsec,debug encryption(3des) 
08:03:16 ipsec,debug pad length = 8 
08:03:16 ipsec,debug 0b000018 ae09f660 7f8824e8 31580541 4c181edb 03da9e47 00000020 00000001 
08:03:16 ipsec,debug 01108d29 e9b2f4eb 7775cd8c d54e5807 8d292f9b 0000109a d79ad4de 89a18d07 
08:03:16 ipsec,debug encryption(3des) 
08:03:16 ipsec,debug with key: 
08:03:16 ipsec,debug 34e76bf3 bdb02b64 47a87b8e e6f5d824 bc49f3e4 3c92dcc9 
08:03:16 ipsec,debug encrypted payload by IV: 
08:03:16 ipsec,debug 53447662 5db8e01f 
08:03:16 ipsec,debug save IV for next: 
08:03:16 ipsec,debug 67a739e8 d6f32bff 
08:03:16 ipsec,debug encrypted. 
08:03:16 ipsec,debug 92 bytes from ROUTER-IP[500] to 75.107.121.2[500] 
08:03:16 ipsec,debug 1 times of 92 bytes message will be sent to 75.107.121.2[500] 
08:03:16 ipsec,debug,packet e9b2f4eb 7775cd8c d54e5807 8d292f9b 08100501 9a12d2e1 0000005c 67c7ae6e 
08:03:16 ipsec,debug,packet a6455b17 9a432ac5 825c2778 ee24535b 5f18701a b7119ee7 74febf2d a578e334 
08:03:16 ipsec,debug,packet 75876d43 18227678 d18a5efe 4c4a875b 075ccf54 67a739e8 d6f32bff 
08:03:16 ipsec,debug sendto Information notify. 
08:03:16 ipsec,debug received a valid R-U-THERE, ACK sent 
08:03:27 l2tp,debug,packet sent control message to 159.121.202.141:1701 from ROUTER-IP:1701 
08:03:27 l2tp,debug,packet     tunnel-id=19, session-id=0, ns=4, nr=4 
08:03:27 l2tp,debug,packet     (M) Message-Type=HELLO 
08:03:27 l2tp,debug,packet rcvd control message (ack) from 159.121.202.141:1701 to ROUTER-IP:1701 
08:03:27 l2tp,debug,packet     tunnel-id=175, session-id=0, ns=4, nr=5

Traffic passed on attempt...

 3    prerouting                                                                                                                                                                                    sniff-tzsp                   20 643 368         190 411
 4    prerouting                                                                                                                                                                                    sniff-tzsp                            0               0
 5    postrouting                                                                                                                                                                                   sniff-tzsp                  523 794 131         360 570
 6    postrouting                                                                                                                                                                                   sniff-tzsp                            0               0

Download Android Trace Here - *REMOVED*
Per usual let me know once you've grabbed a copy of the file

JordanReich · Thu Nov 21, 2019 6:11 pm

Not a problem! I have adjusted my logging rules with the following turned on. I will rerun and provide the results shortly.
@JordanReich, I was also writing the following in some other thread, so I better repeat it here:

To get all of the log, before the connection attempt, run the following:
/log print follow-only file=l2tp-log where topics~"l2tp"
Once the VPN connection fails, break the log print command and then download the resulting text file.

Crap! Should I redo? Or did the log above provide enough?

sindy · Thu Nov 21, 2019 6:16 pm

Better redo, as the log is definitely too small to match. And I could not see the expected message in it.

JordanReich · Thu Nov 21, 2019 6:27 pm

Better redo, as the log is definitely too small to match. And I could not see the expected message in it.

Take 110 ...

L2TP Log...

# nov/21/2019  8:20: 8 by RouterOS 6.44.5
# software id = 1SBQ-KUIK
#
08:20:09 l2tp,debug,packet rcvd control message (ack) from 75.107.121.2:1701 to ROUTER-IP:1701 
08:20:09 l2tp,debug,packet     tunnel-id=143, session-id=0, ns=3292, nr=3290 
08:20:12 l2tp,debug,packet rcvd control message from PHONE-IP:39007 to ROUTER-IP:1701 
08:20:12 l2tp,debug,packet     tunnel-id=0, session-id=0, ns=0, nr=0 
08:20:12 l2tp,debug,packet     (M) Message-Type=SCCRQ 
08:20:12 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:20:12 l2tp,debug,packet     (M) Host-Name="anonymous" 
08:20:12 l2tp,debug,packet     (M) Framing-Capabilities=0x3 
08:20:12 l2tp,debug,packet     (M) Assigned-Tunnel-ID=24958 
08:20:12 l2tp,debug,packet     (M) Receive-Window-Size=1 
08:20:12 l2tp,info first L2TP UDP packet received from PHONE-IP 
08:20:12 l2tp,debug tunnel 178 entering state: wait-ctl-conn 
08:20:12 l2tp,debug,packet sent control message to PHONE-IP:39007 from ROUTER-IP:1701 
08:20:12 l2tp,debug,packet     tunnel-id=24958, session-id=0, ns=0, nr=1 
08:20:12 l2tp,debug,packet     (M) Message-Type=SCCRP 
08:20:12 l2tp,debug,packet     (M) Protocol-Version=0x01:00 
08:20:12 l2tp,debug,packet     (M) Framing-Capabilities=0x1 
08:20:12 l2tp,debug,packet     (M) Bearer-Capabilities=0x0 
08:20:12 l2tp,debug,packet     Firmware-Revision=0x1 
08:20:12 l2tp,debug,packet     (M) Host-Name="ReichHub" 
08:20:12 l2tp,debug,packet     Vendor-Name="MikroTik" 
08:20:12 l2tp,debug,packet     (M) Assigned-Tunnel-ID=178 
08:20:12 l2tp,debug,packet     (M) Receive-Window-Size=4 
08:20:12 l2tp,debug,packet rcvd control message from PHONE-IP:39007 to ROUTER-IP:1701 
08:20:12 l2tp,debug,packet     tunnel-id=178, session-id=0, ns=1, nr=1 
08:20:12 l2tp,debug,packet     (M) Message-Type=SCCCN 
08:20:12 l2tp,debug tunnel 178 entering state: estabilished 
08:20:12 l2tp,debug,packet sent control message (ack) to PHONE-IP:39007 from ROUTER-IP:1701 
08:20:12 l2tp,debug,packet     tunnel-id=24958, session-id=0, ns=1, nr=2 
08:20:12 l2tp,debug,packet rcvd control message from PHONE-IP:39007 to ROUTER-IP:1701 
08:20:12 l2tp,debug,packet     tunnel-id=178, session-id=0, ns=2, nr=1 
08:20:12 l2tp,debug,packet     (M) Message-Type=ICRQ 
08:20:12 l2tp,debug,packet     (M) Assigned-Session-ID=24009 
08:20:12 l2tp,debug,packet     (M) Call-Serial-Number=819288091 
08:20:12 l2tp,debug session 1 entering state: wait-connect 
08:20:12 l2tp,debug,packet sent control message to PHONE-IP:39007 from ROUTER-IP:1701 
08:20:12 l2tp,debug,packet     tunnel-id=24958, session-id=24009, ns=1, nr=3 
08:20:12 l2tp,debug,packet     (M) Message-Type=ICRP 
08:20:12 l2tp,debug,packet     (M) Assigned-Session-ID=1 
08:20:12 l2tp,debug,packet rcvd control message from PHONE-IP:39007 to ROUTER-IP:1701 
08:20:12 l2tp,debug,packet     tunnel-id=178, session-id=1, ns=3, nr=2 
08:20:12 l2tp,debug,packet     (M) Message-Type=ICCN 
08:20:12 l2tp,debug,packet     (M) Tx-Connect-Speed-BPS=100000000 
08:20:12 l2tp,debug,packet     (M) Framing-Type=0x3 
08:20:12 l2tp,debug session 1 entering state: established 
08:20:12 l2tp,debug,packet sent control message (ack) to PHONE-IP:39007 from ROUTER-IP:1701 
08:20:12 l2tp,debug,packet     tunnel-id=24958, session-id=0, ns=2, nr=4 
08:20:12 l2tp,ppp,debug <PHONE-IP>: LCP lowerup 
08:20:12 l2tp,ppp,debug <PHONE-IP>: LCP open 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd LCP ConfReq id=0x1 
08:20:12 l2tp,ppp,debug,packet    <mru 1400> 
08:20:12 l2tp,ppp,debug,packet    <asyncmap 0x0> 
08:20:12 l2tp,ppp,debug,packet    <magic 0x301841fa> 
08:20:12 l2tp,ppp,debug,packet    <pcomp> 
08:20:12 l2tp,ppp,debug,packet    <accomp> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent LCP ConfReq id=0x1 
08:20:12 l2tp,ppp,debug,packet    <mru 1450> 
08:20:12 l2tp,ppp,debug,packet    <magic 0x168ea950> 
08:20:12 l2tp,ppp,debug,packet    <auth  mschap2> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent LCP ConfRej id=0x1 
08:20:12 l2tp,ppp,debug,packet    <asyncmap 0x0> 
08:20:12 l2tp,ppp,debug,packet    <pcomp> 
08:20:12 l2tp,ppp,debug,packet    <accomp> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd LCP ConfAck id=0x1 
08:20:12 l2tp,ppp,debug,packet    <mru 1450> 
08:20:12 l2tp,ppp,debug,packet    <magic 0x168ea950> 
08:20:12 l2tp,ppp,debug,packet    <auth  mschap2> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd LCP ConfReq id=0x2 
08:20:12 l2tp,ppp,debug,packet    <mru 1400> 
08:20:12 l2tp,ppp,debug,packet    <magic 0x301841fa> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent LCP ConfAck id=0x2 
08:20:12 l2tp,ppp,debug,packet    <mru 1400> 
08:20:12 l2tp,ppp,debug,packet    <magic 0x301841fa> 
08:20:12 l2tp,ppp,debug <PHONE-IP>: LCP opened 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent CHAP Challenge id=0x1 
08:20:12 l2tp,ppp,debug,packet     <challenge len=16> 
08:20:12 l2tp,ppp,debug,packet     <name ReichHub> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd CHAP Response id=0x1 
08:20:12 l2tp,ppp,debug,packet     <response len=49> 
08:20:12 l2tp,ppp,debug,packet     <name reichnetwork\admin_bypass> 
08:20:12 l2tp,ppp,info,account admin_bypass logged in, 172.32.0.100 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent CHAP Success id=0x1 
08:20:12 l2tp,ppp,debug,packet     S=3736FF90205987EBC6352EE17342F676BC424E26 
08:20:12 l2tp,ppp,info <l2tp-admin_bypass>: authenticated 
08:20:12 l2tp,ppp,debug <PHONE-IP>: IPCP lowerup 
08:20:12 l2tp,ppp,debug <PHONE-IP>: IPCP open 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent IPCP ConfReq id=0x1 
08:20:12 l2tp,ppp,debug,packet     <addr 172.32.0.1> 
08:20:12 l2tp,ppp,debug <PHONE-IP>: IPV6CP open 
08:20:12 l2tp,ppp,debug <PHONE-IP>: MPLSCP lowerup 
08:20:12 l2tp,ppp,debug <PHONE-IP>: MPLSCP open 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent MPLSCP ConfReq id=0x1 
08:20:12 l2tp,ppp,debug <PHONE-IP>: BCP open 
08:20:12 l2tp,ppp,debug <PHONE-IP>: CCP lowerup 
08:20:12 l2tp,ppp,debug <PHONE-IP>: CCP open 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd CCP ConfReq id=0x1 
08:20:12 l2tp,ppp,debug,packet     <deflate 15> 
08:20:12 l2tp,ppp,debug,packet     <deflate (old) 15> 
08:20:12 l2tp,ppp,debug,packet     <0x15 03 2f> 
08:20:12 l2tp,ppp,debug <PHONE-IP>: received unsupported protocol 0x80fd 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent LCP ProtRej id=0x2 
08:20:12 l2tp,ppp,debug,packet      80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03... 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd IPCP ConfReq id=0x1 
08:20:12 l2tp,ppp,debug,packet     <addr 0.0.0.0> 
08:20:12 l2tp,ppp,debug,packet     <comp VJ f 1> 
08:20:12 l2tp,ppp,debug,packet     <ms-dns 0.0.0.0> 
08:20:12 l2tp,ppp,debug,packet     <ms-dns 0.0.0.0> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent IPCP ConfRej id=0x1 
08:20:12 l2tp,ppp,debug,packet     <comp VJ f 1> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd LCP ProtRej id=0x3 
08:20:12 l2tp,ppp,debug,packet      82 81 01 01 00 04 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd IPCP ConfAck id=0x1 
08:20:12 l2tp,ppp,debug,packet     <addr 172.32.0.1> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd IPCP ConfReq id=0x2 
08:20:12 l2tp,ppp,debug,packet     <addr 0.0.0.0> 
08:20:12 l2tp,ppp,debug,packet     <ms-dns 0.0.0.0> 
08:20:12 l2tp,ppp,debug,packet     <ms-dns 0.0.0.0> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent IPCP ConfNak id=0x2 
08:20:12 l2tp,ppp,debug,packet     <addr 172.32.0.100> 
08:20:12 l2tp,ppp,debug,packet     <ms-dns 172.32.0.1> 
08:20:12 l2tp,ppp,debug,packet     <ms-dns 10.0.0.3> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: rcvd IPCP ConfReq id=0x3 
08:20:12 l2tp,ppp,debug,packet     <addr 172.32.0.100> 
08:20:12 l2tp,ppp,debug,packet     <ms-dns 172.32.0.1> 
08:20:12 l2tp,ppp,debug,packet     <ms-dns 10.0.0.3> 
08:20:12 l2tp,ppp,debug,packet  <PHONE-IP>: sent IPCP ConfAck id=0x3 
08:20:12 l2tp,ppp,debug,packet     <addr 172.32.0.100> 
08:20:12 l2tp,ppp,debug,packet     <ms-dns 172.32.0.1> 
08:20:12 l2tp,ppp,debug,packet     <ms-dns 10.0.0.3> 
08:20:12 l2tp,ppp,debug <PHONE-IP>: IPCP opened 
08:20:12 l2tp,ppp,info <l2tp-admin_bypass>: connected 
08:20:13 l2tp,debug,packet rcvd control message from 71.59.152.62:1701 to ROUTER-IP:1701 
08:20:13 l2tp,debug,packet     tunnel-id=170, session-id=0, ns=947, nr=945 
08:20:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:20:13 l2tp,debug,packet sent control message (ack) to 71.59.152.62:1701 from ROUTER-IP:1701 
08:20:13 l2tp,debug,packet     tunnel-id=53, session-id=0, ns=945, nr=948 
08:20:13 l2tp,debug,packet sent control message to 71.59.152.62:1701 from ROUTER-IP:1701 
08:20:13 l2tp,debug,packet     tunnel-id=53, session-id=0, ns=945, nr=948 
08:20:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:20:13 l2tp,debug,packet rcvd control message (ack) from 71.59.152.62:1701 to ROUTER-IP:1701 
08:20:13 l2tp,debug,packet     tunnel-id=170, session-id=0, ns=948, nr=946 
08:20:27 l2tp,debug,packet sent control message to 159.121.202.141:1701 from ROUTER-IP:1701 
08:20:27 l2tp,debug,packet     tunnel-id=19, session-id=0, ns=21, nr=4 
08:20:27 l2tp,debug,packet     (M) Message-Type=HELLO 
08:20:27 l2tp,debug,packet rcvd control message (ack) from 159.121.202.141:1701 to ROUTER-IP:1701 
08:20:27 l2tp,debug,packet     tunnel-id=175, session-id=0, ns=4, nr=22 
08:21:08 l2tp,debug,packet rcvd control message from 75.107.121.2:1701 to ROUTER-IP:1701 
08:21:08 l2tp,debug,packet     tunnel-id=143, session-id=0, ns=3292, nr=3290 
08:21:08 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:08 l2tp,debug,packet sent control message (ack) to 75.107.121.2:1701 from ROUTER-IP:1701 
08:21:08 l2tp,debug,packet     tunnel-id=12, session-id=0, ns=3290, nr=3293 
08:21:08 l2tp,debug,packet sent control message to 75.107.121.2:1701 from ROUTER-IP:1701 
08:21:08 l2tp,debug,packet     tunnel-id=12, session-id=0, ns=3290, nr=3293 
08:21:08 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:09 l2tp,debug,packet rcvd control message (ack) from 75.107.121.2:1701 to ROUTER-IP:1701 
08:21:09 l2tp,debug,packet     tunnel-id=143, session-id=0, ns=3293, nr=3291 
08:21:12 l2tp,debug,packet sent control message to PHONE-IP:39007 from ROUTER-IP:1701 
08:21:12 l2tp,debug,packet     tunnel-id=24958, session-id=0, ns=2, nr=4 
08:21:12 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:13 l2tp,debug,packet sent control message to PHONE-IP:39007 from ROUTER-IP:1701 
08:21:13 l2tp,debug,packet     tunnel-id=24958, session-id=0, ns=2, nr=4 
08:21:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:13 l2tp,debug,packet sent control message to 71.59.152.62:1701 from ROUTER-IP:1701 
08:21:13 l2tp,debug,packet     tunnel-id=53, session-id=0, ns=946, nr=948 
08:21:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:13 l2tp,debug,packet rcvd control message from 71.59.152.62:1701 to ROUTER-IP:1701 
08:21:13 l2tp,debug,packet     tunnel-id=170, session-id=0, ns=948, nr=946 
08:21:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:13 l2tp,debug,packet sent control message (ack) to 71.59.152.62:1701 from ROUTER-IP:1701 
08:21:13 l2tp,debug,packet     tunnel-id=53, session-id=0, ns=947, nr=949 
08:21:13 l2tp,debug,packet rcvd control message (ack) from 71.59.152.62:1701 to ROUTER-IP:1701 
08:21:13 l2tp,debug,packet     tunnel-id=170, session-id=0, ns=949, nr=947 
08:21:14 l2tp,debug,packet sent control message to PHONE-IP:39007 from ROUTER-IP:1701 
08:21:14 l2tp,debug,packet     tunnel-id=24958, session-id=0, ns=2, nr=4 
08:21:14 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:16 l2tp,debug,packet sent control message to PHONE-IP:39007 from ROUTER-IP:1701 
08:21:16 l2tp,debug,packet     tunnel-id=24958, session-id=0, ns=2, nr=4 
08:21:16 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:20 l2tp,debug,packet sent control message to PHONE-IP:39007 from ROUTER-IP:1701 
08:21:20 l2tp,debug,packet     tunnel-id=24958, session-id=0, ns=2, nr=4 
08:21:20 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:27 l2tp,debug,packet sent control message to 159.121.202.141:1701 from ROUTER-IP:1701 
08:21:27 l2tp,debug,packet     tunnel-id=19, session-id=0, ns=22, nr=4 
08:21:27 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:27 l2tp,debug,packet rcvd control message (ack) from 159.121.202.141:1701 to ROUTER-IP:1701 
08:21:27 l2tp,debug,packet     tunnel-id=175, session-id=0, ns=4, nr=23 
08:21:28 l2tp,debug,packet sent control message to PHONE-IP:39007 from ROUTER-IP:1701 
08:21:28 l2tp,debug,packet     tunnel-id=24958, session-id=0, ns=2, nr=4 
08:21:28 l2tp,debug,packet     (M) Message-Type=HELLO 
08:21:36 l2tp,debug tunnel 178 received no replies, disconnecting 
08:21:36 l2tp,debug tunnel 178 entering state: dead 
08:21:36 l2tp,debug session 1 entering state: dead 
08:21:36 l2tp,ppp,debug <PHONE-IP>: LCP lowerdown 
08:21:36 l2tp,ppp,debug <PHONE-IP>: LCP closed 
08:21:36 l2tp,ppp,debug <PHONE-IP>: CCP lowerdown 
08:21:36 l2tp,ppp,debug <PHONE-IP>: BCP lowerdown 
08:21:36 l2tp,ppp,debug <PHONE-IP>: BCP down event in starting state 
08:21:36 l2tp,ppp,debug <PHONE-IP>: IPCP lowerdown 
08:21:36 l2tp,ppp,debug <PHONE-IP>: IPCP closed 
08:21:36 l2tp,ppp,debug <PHONE-IP>: IPV6CP lowerdown 
08:21:36 l2tp,ppp,debug <PHONE-IP>: IPV6CP down event in starting state 
08:21:36 l2tp,ppp,debug <PHONE-IP>: MPLSCP lowerdown 
08:21:36 l2tp,ppp,debug <PHONE-IP>: CCP close 
08:21:36 l2tp,ppp,debug <PHONE-IP>: BCP close 
08:21:36 l2tp,ppp,debug <PHONE-IP>: IPCP close 
08:21:36 l2tp,ppp,debug <PHONE-IP>: IPV6CP close 
08:21:36 l2tp,ppp,debug <PHONE-IP>: MPLSCP close 
08:21:36 l2tp,ppp,info <l2tp-admin_bypass>: terminating... - hungup 
08:21:36 l2tp,ppp,debug <PHONE-IP>: LCP lowerdown 
08:21:36 l2tp,ppp,debug <PHONE-IP>: LCP down event in starting state 
08:21:36 l2tp,ppp,info,account admin_bypass logged out, 84 1769554 103991611 39996 74885 
08:21:36 l2tp,ppp,info <l2tp-admin_bypass>: disconnected 
08:22:08 l2tp,debug,packet rcvd control message from 75.107.121.2:1701 to ROUTER-IP:1701 
08:22:08 l2tp,debug,packet     tunnel-id=143, session-id=0, ns=3293, nr=3291 
08:22:08 l2tp,debug,packet     (M) Message-Type=HELLO 
08:22:08 l2tp,debug,packet sent control message (ack) to 75.107.121.2:1701 from ROUTER-IP:1701 
08:22:08 l2tp,debug,packet     tunnel-id=12, session-id=0, ns=3291, nr=3294 
08:22:08 l2tp,debug,packet sent control message to 75.107.121.2:1701 from ROUTER-IP:1701 
08:22:08 l2tp,debug,packet     tunnel-id=12, session-id=0, ns=3291, nr=3294 
08:22:08 l2tp,debug,packet     (M) Message-Type=HELLO 
08:22:09 l2tp,debug,packet rcvd control message (ack) from 75.107.121.2:1701 to ROUTER-IP:1701 
08:22:09 l2tp,debug,packet     tunnel-id=143, session-id=0, ns=3294, nr=3292 
08:22:13 l2tp,debug,packet sent control message to 71.59.152.62:1701 from ROUTER-IP:1701 
08:22:13 l2tp,debug,packet     tunnel-id=53, session-id=0, ns=947, nr=949 
08:22:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:22:13 l2tp,debug,packet rcvd control message from 71.59.152.62:1701 to ROUTER-IP:1701 
08:22:13 l2tp,debug,packet     tunnel-id=170, session-id=0, ns=949, nr=947 
08:22:13 l2tp,debug,packet     (M) Message-Type=HELLO 
08:22:13 l2tp,debug,packet sent control message (ack) to 71.59.152.62:1701 from ROUTER-IP:1701 
08:22:13 l2tp,debug,packet     tunnel-id=53, session-id=0, ns=948, nr=950 
08:22:13 l2tp,debug,packet rcvd control message (ack) from 71.59.152.62:1701 to ROUTER-IP:1701 
08:22:13 l2tp,debug,packet     tunnel-id=170, session-id=0, ns=950, nr=948

Data transmitted...

 3    prerouting          sniff-tzsp                    8 747 313          80 931
 4    prerouting          sniff-tzsp                            0               0
 5    postrouting         sniff-tzsp                  217 425 837         149 819
 6    postrouting         sniff-tzsp                            0               0

Android Trace Log - *REMOVED*
Let me know once you got it!

sindy · Thu Nov 21, 2019 6:32 pm

Got it.

sindy · Thu Nov 21, 2019 7:18 pm

Hm. So the log clearly shows the
08:21:12 l2tp,debug,packet sent control message to PHONE-IP:39007 from ROUTER-IP:1701
08:21:12 l2tp,debug,packet tunnel-id=24958, session-id=0, ns=2, nr=4
08:21:12 l2tp,debug,packet (M) Message-Type=HELLO
but the sniff doesn't.

But there are more weird things about the capture, I can see large TCP packets to come from the phone but no matching ESP packets which must have brought them, whilst I do see ESP packets in both directions at other time so it is not an address matching issue. It's a pity you can't tell Android to shut up for a while.

Just for the case, do you have any traffic shaping anywhere in the Tik configuration?

I'll see how it looks like in the lab and will let you know.

JordanReich · Thu Nov 21, 2019 7:43 pm

Hm. So the log clearly shows the
08:21:12 l2tp,debug,packet sent control message to PHONE-IP:39007 from ROUTER-IP:1701
08:21:12 l2tp,debug,packet tunnel-id=24958, session-id=0, ns=2, nr=4
08:21:12 l2tp,debug,packet (M) Message-Type=HELLO
but the sniff doesn't.

But there are more weird things about the capture, I can see large TCP packets to come from the phone but no matching ESP packets which must have brought them, whilst I do see ESP packets in both directions at other time so it is not an address matching issue. It's a pity you can't tell Android to shut up for a while.

Just for the case, do you have any traffic shaping anywhere in the Tik configuration?

I'll see how it looks like in the lab and will let you know.

No I have never had a need to do quota or bandwidth management in my environment. We have 1000/1000 connection to the router and have never had the need.

I can capture some USB debugging from the phone for the duration of the VPN connection - although - I am not sure whether the data would be helpful or not.

Thanks again for all your help on this!

076Lucas · Thu Nov 21, 2019 11:47 pm

Just tried with a brand new Google Pixel phone with different 4G networks, but doesn't work either on that phone. So I will come back on my reply tjat it is maybe an Android bug. Because this one has it also.

Can I maybe create logfiles you will check @Sindy?

sindy · Thu Nov 21, 2019 11:59 pm

OK, so we've definitely found something, as in my case, I can see both the LCP echo request/response (every 30 seconds) and the L2TP Hello message and the zero-length-body response to it:

tshark output code

    1   0.000000  0.000000   192.168.5.1 → 192.168.5.100 PPP LCP 107 Echo Request
    2   0.000002  0.000002   192.168.5.1 → 192.168.5.100 ESP     149 ESP (SPI=0x0dff350d)
    3   0.000002  0.000000 192.168.5.100 → 192.168.5.1   ESP     149 ESP (SPI=0x08d97788)
    4   0.000003  0.000001 192.168.5.100 → 192.168.5.1   PPP LCP 107 Echo Reply
	
    5  30.003278 30.003275   192.168.5.1 → 192.168.5.100 PPP LCP 107 Echo Request
    6  30.003280  0.000002   192.168.5.1 → 192.168.5.100 ESP     149 ESP (SPI=0x0dff350d)
    7  30.003281  0.000001 192.168.5.100 → 192.168.5.1   ESP     149 ESP (SPI=0x08d97788)
    8  30.003282  0.000001 192.168.5.100 → 192.168.5.1   PPP LCP 107 Echo Reply

    9  38.093026  8.089744 192.168.5.100 → 192.168.5.1   ESP     149 ESP (SPI=0x08d97788)
   10  38.093028  0.000002 192.168.5.100 → 192.168.5.1   L2TP    109 Control Message - Hello (tunnel id=13, session id=0)
   11  38.093028  0.000000   192.168.5.1 → 192.168.5.100 L2TP    101 Control Message - ZLB   (tunnel id=45, session id=0)
   12  38.093029  0.000001   192.168.5.1 → 192.168.5.100 ESP     149 ESP (SPI=0x0dff350d)

   13  38.093030  0.000001   192.168.5.1 → 192.168.5.100 L2TP    109 Control Message - Hello (tunnel id=45, session id=0)
   14  38.093031  0.000001   192.168.5.1 → 192.168.5.100 ESP     149 ESP (SPI=0x0dff350d)
   15  38.093032  0.000001 192.168.5.100 → 192.168.5.1   ESP     149 ESP (SPI=0x08d97788)
   16  38.093032  0.000000 192.168.5.100 → 192.168.5.1   L2TP    101 Control Message - ZLB   (tunnel id=13, session id=0)

   17  60.006488 21.913456   192.168.5.1 → 192.168.5.100 PPP LCP 107 Echo Request
   18  60.006490  0.000002   192.168.5.1 → 192.168.5.100 ESP     149 ESP (SPI=0x0dff350d)
   19  60.006491  0.000001 192.168.5.100 → 192.168.5.1   ESP     149 ESP (SPI=0x08d97788)
   20  60.006492  0.000001 192.168.5.100 → 192.168.5.1   PPP LCP 107 Echo Reply

The above matches the l2tp log:

RouterOS log code

21:03:38 l2tp,ppp,debug,packet  <192.168.5.100>: sent LCP EchoReq id=0x20
21:03:38 l2tp,ppp,debug,packet     <magic 0x3b6cb5b9>
21:03:38 l2tp,ppp,debug,packet  <192.168.5.100>: rcvd LCP EchoRep id=0x20
21:03:38 l2tp,ppp,debug,packet     <magic 0x11c96e23>

21:04:08 l2tp,ppp,debug,packet  <192.168.5.100>: sent LCP EchoReq id=0x21
21:04:08 l2tp,ppp,debug,packet     <magic 0x3b6cb5b9>
21:04:08 l2tp,ppp,debug,packet  <192.168.5.100>: rcvd LCP EchoRep id=0x21
21:04:08 l2tp,ppp,debug,packet     <magic 0x11c96e23>

21:04:16 l2tp,debug,packet rcvd control message from 192.168.5.100:1701 to 192.168.5.1:1701
21:04:16 l2tp,debug,packet     tunnel-id=13, session-id=0, ns=2816, nr=2814
21:04:16 l2tp,debug,packet     (M) Message-Type=HELLO
21:04:16 l2tp,debug,packet sent control message (ack) to 192.168.5.100:1701 from 192.168.5.1:1701
21:04:16 l2tp,debug,packet     tunnel-id=45, session-id=0, ns=2814, nr=2817

21:04:16 l2tp,debug,packet sent control message to 192.168.5.100:1701 from 192.168.5.1:1701
21:04:16 l2tp,debug,packet     tunnel-id=45, session-id=0, ns=2814, nr=2817
21:04:16 l2tp,debug,packet     (M) Message-Type=HELLO
21:04:16 l2tp,debug,packet rcvd control message (ack) from 192.168.5.100:1701 to 192.168.5.1:1701
21:04:16 l2tp,debug,packet     tunnel-id=13, session-id=0, ns=2817, nr=2815

21:04:38 l2tp,ppp,debug,packet  <192.168.5.100>: sent LCP EchoReq id=0x22
21:04:38 l2tp,ppp,debug,packet     <magic 0x3b6cb5b9>
21:04:38 l2tp,ppp,debug,packet  <192.168.5.100>: rcvd LCP EchoRep id=0x22
21:04:38 l2tp,ppp,debug,packet     <magic 0x11c96e23>

So I wonder what to do next. Many ESP packets (actually, UDP-encapsulated ESP ones, but that's not the reason) in server->phone direction are not visible in @JordanReich's capture. These must have actually been sent because otherwise the TCP packets they've carried, which can be seen in the capture, would not have made it to the destination and there would have to be tons of retransmissions. This fact indicates a clear malfunction of the measurement method used. Due to this malfunction, we cannot be sure whether the control packets we don't see haven't been sent indeed or whether the same effect which has prevented the ESP ones from making it into the capture has also affected those control ones.

Looking at the capture, it seems to me that the problem is the size of the TZSP packets carrying ESP packets carrying TCP packets that max out the link MTU. These seem to get dropped (or improperly fragmented or reassembled, whatever) on their way to the capturing server. But size is definitely not a problem of the control packets, these are fairly small.

We can reduce the MTU of the TCP packets sent to the phone using a MSS clamping rule:
/ip firewall mangle add chain=postrouting src-address=172.32.0.100 protocol=tcp tcp-flags=syn action=change-mss new-mss=1200
to make sure that this is the only reason why ESP packets are not visible in the capture.

But to check whether the control packets are missing due to capturing method or due to another reason is a different issue.

So @JordanReich, can you repeat the same exercise with some other client than the Android mobile (i.e. a different src/dst-address in the four mangle rules)? In the resulting capture from that client, use a capture filter (ppp and !(ppp.protocol == 0x0021)) || (l2tp.type == 1); it should show you both the L2TP EchoReq/EchoRep ones and the PPP Hello/Ack ones.

On an other-than-Android client, you should also be able to remove any load from the L2TP tunnel by preventing the client from making the tunnel its default gateway and from adding the class-based route, so you could compare whether the control traffic is visible in the capture at least when no payload traffic is transported by the tunnel.

One more point, unlikely to be related to the issue, do you realize that 172.32.0.x is not a private (RFC1918) address?

I'm not sure yet whether it can be clearly named an Android bug. Can you run /ip ipsec policy print detail where dst-address~"public.ip.of.the.phone" while the connection is up and show the (sanitized) result? There should be exactly one such policy with protocol=udp and dst-port matching the one seen in the capture on the same level where phone's public IP is seen (as there are two to three layers of IP:UDP in the captured packets - outermost carries TZSP, the next one carries plaintext L2TP or ESP, and if the L2TP transports UDP payload, it is the innermost one).

JordanReich · Mon Nov 25, 2019 5:18 pm

Sorry for the delay in my response celebrating our two-year anniversary this weekend and the issue had to wait for a bit. Still consider this a high priority. I will review your message shortly including any questions I have so we can continue to move this forward.

Thank you again for all your help on this!

JordanReich · Fri Dec 06, 2019 8:12 pm

Hi Sindy ...

Sorry between the holidays and the last week experiencing the flu I haven't been able to put in the work I've wanted to do on this. If you're willing to proceed I'll dive into this in the next thirty minutes or so and see if we cannot get you some more information.

Thanks!

sindy · Fri Dec 06, 2019 8:19 pm

No need to hurry, I definitely won't get to it today.

JordanReich · Tue Dec 10, 2019 5:40 pm

OK, so we've definitely found something, as in my case, I can see both the LCP echo request/response (every 30 seconds) and the L2TP Hello message and the zero-length-body response to it:

tshark output code
    1   0.000000  0.000000   192.168.5.1 → 192.168.5.100 PPP LCP 107 Echo Request
    2   0.000002  0.000002   192.168.5.1 → 192.168.5.100 ESP     149 ESP (SPI=0x0dff350d)
    3   0.000002  0.000000 192.168.5.100 → 192.168.5.1   ESP     149 ESP (SPI=0x08d97788)
    4   0.000003  0.000001 192.168.5.100 → 192.168.5.1   PPP LCP 107 Echo Reply
	
    5  30.003278 30.003275   192.168.5.1 → 192.168.5.100 PPP LCP 107 Echo Request
    6  30.003280  0.000002   192.168.5.1 → 192.168.5.100 ESP     149 ESP (SPI=0x0dff350d)
    7  30.003281  0.000001 192.168.5.100 → 192.168.5.1   ESP     149 ESP (SPI=0x08d97788)
    8  30.003282  0.000001 192.168.5.100 → 192.168.5.1   PPP LCP 107 Echo Reply

    9  38.093026  8.089744 192.168.5.100 → 192.168.5.1   ESP     149 ESP (SPI=0x08d97788)
   10  38.093028  0.000002 192.168.5.100 → 192.168.5.1   L2TP    109 Control Message - Hello (tunnel id=13, session id=0)
   11  38.093028  0.000000   192.168.5.1 → 192.168.5.100 L2TP    101 Control Message - ZLB   (tunnel id=45, session id=0)
   12  38.093029  0.000001   192.168.5.1 → 192.168.5.100 ESP     149 ESP (SPI=0x0dff350d)

   13  38.093030  0.000001   192.168.5.1 → 192.168.5.100 L2TP    109 Control Message - Hello (tunnel id=45, session id=0)
   14  38.093031  0.000001   192.168.5.1 → 192.168.5.100 ESP     149 ESP (SPI=0x0dff350d)
   15  38.093032  0.000001 192.168.5.100 → 192.168.5.1   ESP     149 ESP (SPI=0x08d97788)
   16  38.093032  0.000000 192.168.5.100 → 192.168.5.1   L2TP    101 Control Message - ZLB   (tunnel id=13, session id=0)

   17  60.006488 21.913456   192.168.5.1 → 192.168.5.100 PPP LCP 107 Echo Request
   18  60.006490  0.000002   192.168.5.1 → 192.168.5.100 ESP     149 ESP (SPI=0x0dff350d)
   19  60.006491  0.000001 192.168.5.100 → 192.168.5.1   ESP     149 ESP (SPI=0x08d97788)
   20  60.006492  0.000001 192.168.5.100 → 192.168.5.1   PPP LCP 107 Echo Reply
The above matches the l2tp log:
RouterOS log code
21:03:38 l2tp,ppp,debug,packet  <192.168.5.100>: sent LCP EchoReq id=0x20
21:03:38 l2tp,ppp,debug,packet     <magic 0x3b6cb5b9>
21:03:38 l2tp,ppp,debug,packet  <192.168.5.100>: rcvd LCP EchoRep id=0x20
21:03:38 l2tp,ppp,debug,packet     <magic 0x11c96e23>

21:04:08 l2tp,ppp,debug,packet  <192.168.5.100>: sent LCP EchoReq id=0x21
21:04:08 l2tp,ppp,debug,packet     <magic 0x3b6cb5b9>
21:04:08 l2tp,ppp,debug,packet  <192.168.5.100>: rcvd LCP EchoRep id=0x21
21:04:08 l2tp,ppp,debug,packet     <magic 0x11c96e23>

21:04:16 l2tp,debug,packet rcvd control message from 192.168.5.100:1701 to 192.168.5.1:1701
21:04:16 l2tp,debug,packet     tunnel-id=13, session-id=0, ns=2816, nr=2814
21:04:16 l2tp,debug,packet     (M) Message-Type=HELLO
21:04:16 l2tp,debug,packet sent control message (ack) to 192.168.5.100:1701 from 192.168.5.1:1701
21:04:16 l2tp,debug,packet     tunnel-id=45, session-id=0, ns=2814, nr=2817

21:04:16 l2tp,debug,packet sent control message to 192.168.5.100:1701 from 192.168.5.1:1701
21:04:16 l2tp,debug,packet     tunnel-id=45, session-id=0, ns=2814, nr=2817
21:04:16 l2tp,debug,packet     (M) Message-Type=HELLO
21:04:16 l2tp,debug,packet rcvd control message (ack) from 192.168.5.100:1701 to 192.168.5.1:1701
21:04:16 l2tp,debug,packet     tunnel-id=13, session-id=0, ns=2817, nr=2815

21:04:38 l2tp,ppp,debug,packet  <192.168.5.100>: sent LCP EchoReq id=0x22
21:04:38 l2tp,ppp,debug,packet     <magic 0x3b6cb5b9>
21:04:38 l2tp,ppp,debug,packet  <192.168.5.100>: rcvd LCP EchoRep id=0x22
21:04:38 l2tp,ppp,debug,packet     <magic 0x11c96e23>
So I wonder what to do next. Many ESP packets (actually, UDP-encapsulated ESP ones, but that's not the reason) in server->phone direction are not visible in @JordanReich's capture. These must have actually been sent because otherwise the TCP packets they've carried, which can be seen in the capture, would not have made it to the destination and there would have to be tons of retransmissions. This fact indicates a clear malfunction of the measurement method used. Due to this malfunction, we cannot be sure whether the control packets we don't see haven't been sent indeed or whether the same effect which has prevented the ESP ones from making it into the capture has also affected those control ones.

Looking at the capture, it seems to me that the problem is the size of the TZSP packets carrying ESP packets carrying TCP packets that max out the link MTU. These seem to get dropped (or improperly fragmented or reassembled, whatever) on their way to the capturing server. But size is definitely not a problem of the control packets, these are fairly small.

We can reduce the MTU of the TCP packets sent to the phone using a MSS clamping rule:
/ip firewall mangle add chain=postrouting src-address=172.32.0.100 protocol=tcp tcp-flags=syn action=change-mss new-mss=1200
to make sure that this is the only reason why ESP packets are not visible in the capture.

But to check whether the control packets are missing due to capturing method or due to another reason is a different issue.

So @JordanReich, can you repeat the same exercise with some other client than the Android mobile (i.e. a different src/dst-address in the four mangle rules)? In the resulting capture from that client, use a capture filter (ppp and !(ppp.protocol == 0x0021)) || (l2tp.type == 1); it should show you both the L2TP EchoReq/EchoRep ones and the PPP Hello/Ack ones.

On an other-than-Android client, you should also be able to remove any load from the L2TP tunnel by preventing the client from making the tunnel its default gateway and from adding the class-based route, so you could compare whether the control traffic is visible in the capture at least when no payload traffic is transported by the tunnel.

One more point, unlikely to be related to the issue, do you realize that 172.32.0.x is not a private (RFC1918) address?

I'm not sure yet whether it can be clearly named an Android bug. Can you run /ip ipsec policy print detail where dst-address~"public.ip.of.the.phone" while the connection is up and show the (sanitized) result? There should be exactly one such policy with protocol=udp and dst-port matching the one seen in the capture on the same level where phone's public IP is seen (as there are two to three layers of IP:UDP in the captured packets - outermost carries TZSP, the next one carries plaintext L2TP or ESP, and if the L2TP transports UDP payload, it is the innermost one).

Finally getting around to this. I can use the VPN connection that works without any issue between the remote windows machine and the router as an alternative source.

Will that work for your needs?

sindy · Tue Dec 10, 2019 5:47 pm

Will that work for your needs?

Sure.

076Lucas · Fri Jan 10, 2020 1:11 pm

Any update on this? Can I help with some testing?

fedus · Mon Jan 20, 2020 3:04 pm

Hey,

just chiming in that I have exactly the same issue, also with a Pixel 3 device and newest Android (A10 with Jan 2020 security patch).
Router is HAP AC with ROS 6.46.2.

Quite frustrating.

JordanReich · Wed Jan 22, 2020 2:28 am

Sorry guys I've been buried the last couple months dealing with a mountain of other things that became a higher priority.

Can't guarantee that I'll for sure get to it but I'll try to finally get you an output Sindy so we can move forward on this. As I would still like to find a correction if possible.

Give me 3-4 hours.

JordanReich · Wed Jan 22, 2020 7:45 am

Alright ...
Sindy let me know when your on tomorrow and I should be able to send you what you requested above - and will be available most of the morning starting at around 07:30 AM PST.

sindy · Wed Jan 22, 2020 4:47 pm

The problem is that now it's me who is busy doing other things, so today, tomorrow and Friday are out of question. And next week won't be much better.

Not related to the previous statement, just to give you an idea - CET at my end.

JordanReich · Wed Jan 22, 2020 5:06 pm

No worries. I completely understand thank you for the time zone.
Would you like me to compile and provide the logging now so you have it, or wait and catch up with you in a week or so?

sindy · Wed Jan 22, 2020 5:19 pm

Would you like me to compile and provide the logging now so you have it, or wait and catch up with you in a week or so?

Whatever you can do without my online cooperation will be fine as I can then have a look at the files while offline. But in that case I hope you've noted down my ID when I was downloading the pcap files last time so you can now make the new ones only accessible to me, so that we don't need to synchronize tightly on publishing, retrieving, and retracting them.

JordanReich · Tue Feb 04, 2020 7:39 pm

For those of you experiencing this issue please add your feedback here as well:
https://issuetracker.google.com/issues/148526915

At this point based upon additional research this is happening across enough systems to lead to a conclusion that it appears to be a defect on Androids end. We set up the same VPN system on the Unify security gateway with the exact same results.

Thanks!

jspace · Fri Sep 11, 2020 3:17 am

For those of you experiencing this issue please add your feedback here as well:
https://issuetracker.google.com/issues/148526915

At this point based upon additional research this is happening across enough systems to lead to a conclusion that it appears to be a defect on Androids end. We set up the same VPN system on the Unify security gateway with the exact same results.

Thanks!

Google Pixel 3a Android 11 L2TP/IPsec is working fine with SoftEther VPN Server, without drops. ("SoftEther VPN Server Ver 4.34 - Build 9745 - rtm" running on Windows 10 x64)
If I use RouterOS as L2TP/IPsec vpn server I have always the drop issue after about 80 seconds.
Also when I had Android 10 the L2TP/IPsec was the same, with SoftEther working fine, with RouterOS drops.

Android L2TP/IPsec client isn't "defective" with all L2TP/IPsec servers. Maybe is a bug of Android when connected with some L2TP servers, like RouterOS, or maybe is a bug of the L2TP server libraries that Mikrotik and other brands are using on their OS.

.pem code

tshark output code

RouterOS log code

tshark output code

RouterOS log code

Who is online