This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Connection Problem between ASLV6 Release 6.310 and ASC 8.21

Hello everybody,

as the Headline says I have a problem to etablish a connection between our Firewall and the notebook of a colleague if he is working from home behind a router. If he try to etabish a connection without a router he could connect to our firewall.

IPSEC PASSTROUGH is activated on his router.

Here is the log from the Client: (profilename and Firewall IP changed)

17.07.2007 22:22:28  Extended Firewall: is stopped
17.07.2007 22:22:28  Installed as a full license.
17.07.2007 22:22:28  Warning: could not open file - c:\crypt.key
17.07.2007 22:22:28  Found adapter: 11a/b/g Wireless LAN Mini PCI Adapter with MTU 1500 bytes
17.07.2007 22:22:28  Found adapter: Intel(R) PRO/1000 MT Mobile Connection with MTU 1500 bytes
17.07.2007 22:22:28  Found adapter: AT&T with MTU 1370 bytes
17.07.2007 22:22:28  Found adapter: NdisWan Adapter with MTU 1400 bytes
17.07.2007 22:22:28  Installed as a full license.
17.07.2007 22:22:30  IPSDIALCHAN::start building connection
17.07.2007 22:22:46  WmPowerBroadCast:  WParam =  10
17.07.2007 22:23:08  IPSDIALCHAN::start building connection
17.07.2007 22:23:08  NCPIKE-phase1:name(user1) - outgoing connect request - main mode.
17.07.2007 22:23:08  XMIT_MSG1_MAIN - user1
17.07.2007 22:23:08  RECV_MSG2_MAIN - user1
17.07.2007 22:23:08  IKE phase I: Setting LifeTime to 7800 seconds
17.07.2007 22:23:08  user1 ->Support for NAT-T version - 9
17.07.2007 22:23:08  XMIT_MSG3_MAIN - user1
17.07.2007 22:23:08  IPSDIAL->FINAL_TUNNEL_ENDPOINT:SERVER-IP
17.07.2007 22:23:08  RECV_MSG4_MAIN - user1
17.07.2007 22:23:08  Turning on NATD mode - user1 - 1
17.07.2007 22:23:08  XMIT_MSG5_MAIN - user1
17.07.2007 22:23:09  XMIT_MSG5_MAIN_RESUME - user1
17.07.2007 22:23:13  WmPowerBroadCast:  WParam =  10
17.07.2007 22:23:47  NCPIKE-phase2:name(user1) - error - cleared by phase1
17.07.2007 22:23:47  IPSDIAL  - disconnected from user1 on channel 1.
17.07.2007 22:24:13  WmPowerBroadCast:  WParam =  10
17.07.2007 22:25:13  WmPowerBroadCast:  WParam =  10
17.07.2007 22:26:14  WmPowerBroadCast:  WParam =  10
17.07.2007 22:27:14  WmPowerBroadCast:  WParam =  10
17.07.2007 22:28:14  WmPowerBroadCast:  WParam =  10
17.07.2007 22:29:14  WmPowerBroadCast:  WParam =  10
17.07.2007 22:30:14  WmPowerBroadCast:  WParam =  10
17.07.2007 22:31:15  WmPowerBroadCast:  WParam =  10
17.07.2007 22:32:15  WmPowerBroadCast:  WParam =  10
17.07.2007 22:33:15  WmPowerBroadCast:  WParam =  10
17.07.2007 22:34:15  WmPowerBroadCast:  WParam =  10
17.07.2007 22:34:46  WmPowerBroadCast:  WParam =  10
17.07.2007 22:35:16  WmPowerBroadCast:  WParam =  10
17.07.2007 22:36:16  WmPowerBroadCast:  WParam =  10
17.07.2007 22:36:45  IPSDIALCHAN::start building connection
17.07.2007 22:37:07  IPSDIALCHAN::start building connection
17.07.2007 22:37:07  NCPIKE-phase1:name(user1) - outgoing connect request - main mode.
17.07.2007 22:37:07  XMIT_MSG1_MAIN - user1
17.07.2007 22:37:07  RECV_MSG2_MAIN - user1
17.07.2007 22:37:07  IPSDIAL->FINAL_TUNNEL_ENDPOINT:SERVER-IP
17.07.2007 22:37:07  IKE phase I: Setting LifeTime to 7800 seconds
17.07.2007 22:37:07  user1 ->Support for NAT-T version - 9
17.07.2007 22:37:07  XMIT_MSG3_MAIN - user1
17.07.2007 22:37:08  RECV_MSG4_MAIN - user1
17.07.2007 22:37:08  Turning on NATD mode - user1 - 1
17.07.2007 22:37:08  XMIT_MSG5_MAIN - user1
17.07.2007 22:37:08  XMIT_MSG5_MAIN_RESUME - user1
17.07.2007 22:37:16  WmPowerBroadCast:  WParam =  10
17.07.2007 22:37:47  NCPIKE-phase2:name(user1) - error - cleared by phase1
17.07.2007 22:37:47  IPSDIAL  - disconnected from user1 on channel 1.
17.07.2007 22:38:16  WmPowerBroadCast:  WParam =  10
17.07.2007 22:39:16  WmPowerBroadCast:  WParam =  10
17.07.2007 22:40:06  IPSDIALCHAN::start building connection
17.07.2007 22:40:16  WmPowerBroadCast:  WParam =  10
17.07.2007 22:40:20  IPSDIALCHAN::start building connection
17.07.2007 22:40:20  NCPIKE-phase1:name(user1) - outgoing connect request - main mode.
17.07.2007 22:40:20  XMIT_MSG1_MAIN - user1
17.07.2007 22:40:20  RECV_MSG2_MAIN - user1
17.07.2007 22:40:20  IPSDIAL->FINAL_TUNNEL_ENDPOINT:SERVER-IP
17.07.2007 22:40:20  IKE phase I: Setting LifeTime to 7800 seconds
17.07.2007 22:40:20  user1 ->Support for NAT-T version - 9
17.07.2007 22:40:20  XMIT_MSG3_MAIN - user1
17.07.2007 22:40:20  RECV_MSG4_MAIN - user1
17.07.2007 22:40:20  Turning on NATD mode - user1 - 1
17.07.2007 22:40:21  XMIT_MSG5_MAIN - user1
17.07.2007 22:40:21  XMIT_MSG5_MAIN_RESUME - user1
17.07.2007 22:41:00  NCPIKE-phase2:name(user1) - error - cleared by phase1
17.07.2007 22:41:00  IPSDIAL  - disconnected from user1 on channel 1.
17.07.2007 22:41:16  WmPowerBroadCast:  WParam =  10
17.07.2007 22:42:16  WmPowerBroadCast:  WParam =  10
17.07.2007 22:43:16  WmPowerBroadCast:  WParam =  10
17.07.2007 22:44:17  WmPowerBroadCast:  WParam =  10
17.07.2007 22:45:17  WmPowerBroadCast:  WParam =  10
17.07.2007 22:46:18  WmPowerBroadCast:  WParam =  10
17.07.2007 22:46:46  WmPowerBroadCast:  WParam =  10
17.07.2007 22:47:18  WmPowerBroadCast:  WParam =  10
17.07.2007 22:48:18  WmPowerBroadCast:  WParam =  10

Firewall Log is in the next post.

If you need more infomation to help me don't hesitate to ask for more informatoin.

Best regards

Christian


This thread was automatically locked due to age.
  • And here the Firewall-Log: (userprofiles changed)

    2007:07:17-22:51:24 (none) pluto[5398]: | next event EVENT_PENDING_PHASE2 in 0 seconds
    2007:07:17-22:51:24 (none) pluto[5398]: |
    2007:07:17-22:51:24 (none) pluto[5398]: | *time to handle event
    2007:07:17-22:51:24 (none) pluto[5398]: | handling event EVENT_PENDING_PHASE2
    2007:07:17-22:51:24 (none) pluto[5398]: | event after this is EVENT_SHUNT_SCAN in 120 seconds
    2007:07:17-22:51:24 (none) pluto[5398]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
    2007:07:17-22:51:24 (none) pluto[5398]: | pending review: connection "D_user1_0" was not up, skipped
    2007:07:17-22:51:24 (none) pluto[5398]: | pending review: connection "D_user2_0" was not up, skipped
    2007:07:17-22:51:24 (none) pluto[5398]: | pending review: connection "D_user3_0" was not up, skipped
    2007:07:17-22:51:24 (none) pluto[5398]: | pending review: connection "D_user4_0" was not up, skipped
    2007:07:17-22:51:24 (none) pluto[5398]: | next event EVENT_PENDING_PHASE2 in 120 seconds
    2007:07:17-22:52:41 (none) pluto[5398]: |
    2007:07:17-22:52:41 (none) pluto[5398]: | *received 248 bytes from 217.227.255.82:500 on eth4 (port=500)
    2007:07:17-22:52:41 (none) pluto[5398]: | processing packet with exchange type=ISAKMP_XCHG_IDPROT (2)
    2007:07:17-22:52:41 (none) pluto[5398]: packet from 217.227.255.82:500: ignoring unknown Vendor ID payload [da8e937880010000]
    2007:07:17-22:52:41 (none) pluto[5398]: packet from 217.227.255.82:500: received Vendor ID payload [XAUTH]
    2007:07:17-22:52:41 (none) pluto[5398]: packet from 217.227.255.82:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03] method set to=108
    2007:07:17-22:52:41 (none) pluto[5398]: packet from 217.227.255.82:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but already using method 108
    2007:07:17-22:52:41 (none) pluto[5398]: packet from 217.227.255.82:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
    2007:07:17-22:52:41 (none) pluto[5398]: packet from 217.227.255.82:500: received Vendor ID payload [RFC 3947] method set to=109
    2007:07:17-22:52:41 (none) pluto[5398]: packet from 217.227.255.82:500: received Vendor ID payload [Dead Peer Detection]
    2007:07:17-22:52:41 (none) pluto[5398]: packet from 217.227.255.82:500: ignoring unknown Vendor ID payload [101fb0b35c5a4f4c08b919f1ce0cd8a2]
    2007:07:17-22:52:41 (none) pluto[5398]: packet from 217.227.255.82:500: received Vendor ID payload [Cisco-Unity]
    2007:07:17-22:52:41 (none) pluto[5398]: | alg_info_addref() alg_info->ref_cnt=24
    2007:07:17-22:52:41 (none) pluto[5398]: | alg_info_addref() alg_info->ref_cnt=24
    2007:07:17-22:52:41 (none) pluto[5398]: | alg_info_addref() alg_info->ref_cnt=25
    2007:07:17-22:52:41 (none) pluto[5398]: | alg_info_addref() alg_info->ref_cnt=25
    2007:07:17-22:52:41 (none) pluto[5398]: | instantiated "D_user1_0" for 217.227.255.82
    2007:07:17-22:52:41 (none) pluto[5398]: | creating state object #50 at 0x81249c0
    2007:07:17-22:52:41 (none) pluto[5398]: | processing connection D_user1_0[22] 217.227.255.82
    2007:07:17-22:52:41 (none) pluto[5398]: | ICOOKIE: a0 ac e8 e1 6b dc 69 17
    2007:07:17-22:52:41 (none) pluto[5398]: | RCOOKIE: db e7 07 16 48 f3 01 08
    2007:07:17-22:52:41 (none) pluto[5398]: | peer: d9 e3 ff 52
    2007:07:17-22:52:41 (none) pluto[5398]: | state hash entry 22
    2007:07:17-22:52:41 (none) pluto[5398]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #50
    2007:07:17-22:52:41 (none) pluto[5398]: "D_user1_0"[22] 217.227.255.82 #50: responding to Main Mode from unknown peer 217.227.255.82
    2007:07:17-22:52:41 (none) pluto[5398]: | complete state transition with STF_OK
    2007:07:17-22:52:41 (none) pluto[5398]: "D_user1_0"[22] 217.227.255.82 #50: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
    2007:07:17-22:52:41 (none) pluto[5398]: | sending reply packet to 217.227.255.82:500 (from port=500)
    2007:07:17-22:52:41 (none) pluto[5398]: | sending 140 bytes for STATE_MAIN_R0 through eth4:500 to 217.227.255.82:500:
    2007:07:17-22:52:41 (none) pluto[5398]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #50
    2007:07:17-22:52:41 (none) pluto[5398]: "D_user1_0"[22] 217.227.255.82 #50: STATE_MAIN_R1: sent MR1, expecting MI2
    2007:07:17-22:52:41 (none) pluto[5398]: | modecfg pull: quirk-poll policy[:P]ush not-client
    2007:07:17-22:52:41 (none) pluto[5398]: | phase 1 is done, looking for phase 1 to unpend
    2007:07:17-22:52:41 (none) pluto[5398]: | next event EVENT_RETRANSMIT in 10 seconds for #50
    2007:07:17-22:52:41 (none) pluto[5398]: |
    2007:07:17-22:52:41 (none) pluto[5398]: | *received 308 bytes from 217.227.255.82:500 on eth4 (port=500)
    2007:07:17-22:52:41 (none) pluto[5398]: | processing packet with exchange type=ISAKMP_XCHG_IDPROT (2)
    2007:07:17-22:52:41 (none) pluto[5398]: | ICOOKIE: a0 ac e8 e1 6b dc 69 17
    2007:07:17-22:52:41 (none) pluto[5398]: | RCOOKIE: db e7 07 16 48 f3 01 08
    2007:07:17-22:52:41 (none) pluto[5398]: | peer: d9 e3 ff 52
    2007:07:17-22:52:41 (none) pluto[5398]: | state hash entry 22
    2007:07:17-22:52:41 (none) pluto[5398]: | peer and cookies match on #50, provided msgid 00000000 vs 00000000
    2007:07:17-22:52:41 (none) pluto[5398]: | state object #50 found, in STATE_MAIN_R1
    2007:07:17-22:52:41 (none) pluto[5398]: | processing connection D_user1_0[22] 217.227.255.82
    2007:07:17-22:52:41 (none) pluto[5398]: "D_user1_0"[22] 217.227.255.82 #50: NAT-Traversal: Result using 3: peer is NATed
    2007:07:17-22:52:41 (none) pluto[5398]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 60 seconds
    2007:07:17-22:52:41 (none) pluto[5398]: | helper -1 doing build_kenonce op id: 0
    2007:07:17-22:52:41 (none) pluto[5398]: | processing connection D_user1_0[22] 217.227.255.82
    2007:07:17-22:52:41 (none) pluto[5398]: | started looking for secret for C=de, ST=***X, L=***x, O=cccc, OU=IT, CN=firewall, E=sign@domain.tld->C=de, ST=***X, L=***x, O=cccc, OU=IT, CN=user1, E=user1@domain.tld of kind PPK_PSK
    2007:07:17-22:52:41 (none) pluto[5398]: | instantiating him to 0.0.0.0
    2007:07:17-22:52:41 (none) pluto[5398]: | actually looking for secret for C=de, ST=***X, L=***x, O=cccc, OU=IT, CN=firewall, E=sign@domain.tld->0.0.0.0 of kind PPK_PSK
    2007:07:17-22:52:41 (none) pluto[5398]: | concluding with best_match=0 best=(nil) (lineno=-1)
    2007:07:17-22:52:41 (none) pluto[5398]: | complete state transition with STF_OK
    2007:07:17-22:52:41 (none) pluto[5398]: "D_user1_0"[22] 217.227.255.82 #50: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
    2007:07:17-22:52:41 (none) pluto[5398]: | sending reply packet to 217.227.255.82:500 (from port=500)
    2007:07:17-22:52:41 (none) pluto[5398]: | sending 284 bytes for STATE_MAIN_R1 through eth4:500 to 217.227.255.82:500:
    2007:07:17-22:52:41 (none) pluto[5398]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #50
    2007:07:17-22:52:41 (none) pluto[5398]: "D_user1_0"[22] 217.227.255.82 #50: STATE_MAIN_R2: sent MR2, expecting MI3
    2007:07:17-22:52:41 (none) pluto[5398]: | modecfg pull: quirk-poll policy[:P]ush not-client
    2007:07:17-22:52:41 (none) pluto[5398]: | phase 1 is done, looking for phase 1 to unpend
    2007:07:17-22:52:41 (none) pluto[5398]: | complete state transition with STF_INLINE
    2007:07:17-22:52:41 (none) pluto[5398]: | next event EVENT_RETRANSMIT in 10 seconds for #50
    2007:07:17-22:52:51 (none) pluto[5398]: |
    2007:07:17-22:52:51 (none) pluto[5398]: | *time to handle event
    2007:07:17-22:52:51 (none) pluto[5398]: | handling event EVENT_RETRANSMIT
    2007:07:17-22:52:51 (none) pluto[5398]: | event after this is EVENT_PENDING_PHASE2 in 33 seconds
    2007:07:17-22:52:51 (none) pluto[5398]: | processing connection D_user1_0[22] 217.227.255.82
    2007:07:17-22:52:51 (none) pluto[5398]: | handling event EVENT_RETRANSMIT for 217.227.255.82 "D_user1_0" #50
    2007:07:17-22:52:51 (none) pluto[5398]: | sending 284 bytes for EVENT_RETRANSMIT through eth4:500 to 217.227.255.82:500:
    2007:07:17-22:52:51 (none) pluto[5398]: | inserting event EVENT_RETRANSMIT, timeout in 20 seconds for #50
    2007:07:17-22:52:51 (none) pluto[5398]: | next event EVENT_RETRANSMIT in 20 seconds for #50
    2007:07:17-22:52:52 (none) pluto[5398]: |
    2007:07:17-22:52:52 (none) pluto[5398]: | *received 1408 bytes from 217.227.255.82:500 on eth4 (port=500)
    2007:07:17-22:52:52 (none) pluto[5398]: packet from 217.227.255.82:500: next payload type of ISAKMP Message has an unknown value: 72
    2007:07:17-22:52:52 (none) pluto[5398]: packet from 217.227.255.82:500: sending notification INVALID_MAJOR_VERSION to 217.227.255.82:500
    2007:07:17-22:52:52 (none) pluto[5398]: | sending 40 bytes for notification packet through eth4:500 to 217.227.255.82:500:
    2007:07:17-22:52:52 (none) pluto[5398]: | next event EVENT_RETRANSMIT in 19 seconds for #50
    2007:07:17-22:53:11 (none) pluto[5398]: |
    2007:07:17-22:53:11 (none) pluto[5398]: | *time to handle event
    2007:07:17-22:53:11 (none) pluto[5398]: | handling event EVENT_RETRANSMIT
    2007:07:17-22:53:11 (none) pluto[5398]: | event after this is EVENT_PENDING_PHASE2 in 13 seconds
    2007:07:17-22:53:11 (none) pluto[5398]: | processing connection D_user1_0[22] 217.227.255.82
    2007:07:17-22:53:11 (none) pluto[5398]: | handling event EVENT_RETRANSMIT for 217.227.255.82 "D_user1_0" #50
    2007:07:17-22:53:11 (none) pluto[5398]: | sending 284 bytes for EVENT_RETRANSMIT through eth4:500 to 217.227.255.82:500:
    2007:07:17-22:53:11 (none) pluto[5398]: | inserting event EVENT_RETRANSMIT, timeout in 40 seconds for #50
    2007:07:17-22:53:11 (none) pluto[5398]: | next event EVENT_PENDING_PHASE2 in 13 seconds

    If you need more infomation to help me don't hesitate to ask for more informatoin.

    Best regards

    Christian