<html>
<head>
<meta http-equiv="content-type" content="text/html; charset=ISO-8859-15">
</head>
<body bgcolor="#FFFFFF" text="#000000">
Hi,<br>
<br>
I really like the android strongswan app. It is small,
battery-efficient and gives immediate VPN access after a connection
problem (i.e. after a short coverage hole on the road..). I do not
know any better app. But as always, there's a little problem. After
some hours, or perhaps days, the tunnel is down. I receive these
errors in the log:<br>
<pre>09-19 09:11:24.950 I/charon (12923): 08[IKE] giving up after 10 path probings
09-19 09:11:24.950 I/charon (12923): 08[IKE] looking up interface for virtual IP 10.150.240.194 failed
09-19 09:11:24.950 I/charon (12923): 08[IKE] looking up interface for virtual IP 2abc:123:123:8002:1::12 failed
09-19 09:11:24.950 I/charon (12923): 08[IKE] restarting CHILD_SA android
09-19 09:11:24.950 I/charon (12923): 08[IKE] initiating IKE_SA android[5] to X.Y.Z.65
09-19 09:11:27.575 D/AlarmManagerService( 2371): Kernel timezone updated to -120 minutes west of GMT
09-19 09:11:27.580 D/Tethering( 2371): MasterInitialState.processMessage what=3
09-19 09:11:27.840 I/charon (12923): 08[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
09-19 09:11:27.845 I/charon (12923): 08[NET] sending packet: from 192.168.203.96[49398] to X.Y.Z.65[4500] (648 bytes)
09-19 09:11:28.100 D/PicasaUploaderSyncManager( 619): active network: NetworkInfo: type: mobile[UMTS], state: CONNECTED/CONNECTED, reason: (unspecified), extra: web.vodafone.de, roaming: false, failover: false,
isAvailable: true
09-19 09:11:28.205 D/GCM ( 5657): GcmService start Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x8000010 cmp=com.google.android.gms/.gcm.GcmService (has extras) } android.net.conn.CONNECTIVITY_CHAN
GE
09-19 09:11:28.495 D/dalvikvm(27068): GC_EXPLICIT freed 274K, 49% free 5570K/10780K, paused 1ms+13ms, total 83ms
09-19 09:11:28.625 D/dalvikvm( 2371): GC_EXPLICIT freed 1075K, 27% free 22526K/30740K, paused 3ms+6ms, total 75ms
09-19 09:11:29.775 D/AlarmManagerService( 2371): Kernel timezone updated to -120 minutes west of GMT
09-19 09:11:29.845 I/charon (12923): 14[IKE] retransmit 1 of request with message ID 0
09-19 09:11:29.845 I/charon (12923): 14[NET] sending packet: from 192.168.203.96[49398] to X.Y.Z.65[4500] (648 bytes)
09-19 09:11:30.030 I/charon (12923): 15[NET] received packet: from X.Y.Z.65[4500] to 10.27.3.195[49398] (465 bytes)
09-19 09:11:30.030 I/charon (12923): 15[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
09-19 09:11:30.325 I/charon (12923): 15[IKE] local host is behind NAT, sending keep alives
09-19 09:11:30.330 I/charon (12923): 15[IKE] received cert request for "C=DE, O=test.loc, CN=test.loc"
09-19 09:11:30.330 I/charon (12923): 15[IKE] sending cert request for "C=DE, CN=test.loc"
09-19 09:11:30.330 I/charon (12923): 15[IKE] sending cert request for "C=DE, O=test.loc, CN=test.loc"
09-19 09:11:30.395 I/charon (12923): 15[IKE] authentication of 'C=DE, O=test.loc, CN=avalentin-nexus' (myself) with RSA signature successful
09-19 09:11:30.395 I/charon (12923): 15[IKE] sending end entity cert "C=DE, O=test.loc, CN=avalentin-nexus"
09-19 09:11:30.395 I/charon (12923): 15[IKE] establishing CHILD_SA android{3}
09-19 09:11:30.395 I/charon (12923): 15[ENC] generating IKE_AUTH request 1 [ IDi CERT N(INIT_CONTACT) CERTREQ AUTH CP(ADDR ADDR6 DNS DNS6) N(ESP_TFC_PAD_N) SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(MULT_AUTH) N(
EAP_ONLY) ]
09-19 09:11:30.400 I/charon (12923): 15[NET] sending packet: from 192.168.203.96[49398] to X.Y.Z.65[4500] (1900 bytes)
09-19 09:11:30.660 D/dalvikvm(27068): GC_EXPLICIT freed 242K, 49% free 5549K/10780K, paused 2ms+5ms, total 31ms
09-19 09:11:30.755 D/dalvikvm(32532): GC_EXPLICIT freed 553K, 72% free 3097K/10780K, paused 4ms+11ms, total 69ms
09-19 09:11:30.800 I/charon (12923): 16[NET] received packet: from X.Y.Z.65[4500] to 10.27.3.195[49398] (1836 bytes)
09-19 09:11:30.800 I/charon (12923): 16[ENC] parsed IKE_AUTH response 1 [ IDr CERT AUTH CP(ADDR ADDR6 DNS) SA TSi TSr N(MOBIKE_SUP) N(ADD_6_ADDR) ]
09-19 09:11:30.805 I/charon (12923): 16[IKE] received end entity cert "C=DE, O=test.loc, CN=vpn.test.loc"
09-19 09:11:30.805 I/charon (12923): 16[CFG] using certificate "C=DE, O=test.loc, CN=vpn.test.loc"
09-19 09:11:30.805 I/charon (12923): 16[CFG] using trusted ca certificate "C=DE, O=test.loc, CN=test.loc"
09-19 09:11:30.805 I/charon (12923): 16[CFG] reached self-signed root ca with a path length of 0
09-19 09:11:30.805 I/charon (12923): 16[IKE] authentication of 'vpn.test.loc' with RSA signature successful
09-19 09:11:30.805 I/charon (12923): 16[IKE] IKE_SA android[5] established between 192.168.203.96[C=DE, O=test.loc, CN=avalentin-nexus]...X.Y.Z.65[vpn.test.loc]
09-19 09:11:30.805 I/charon (12923): 16[IKE] scheduling rekeying in 35411s
09-19 09:11:30.805 I/charon (12923): 16[IKE] maximum IKE_SA lifetime 36011s
09-19 09:11:30.805 I/charon (12923): 16[IKE] looking up interface for virtual IP 10.150.240.194 failed
09-19 09:11:30.805 I/charon (12923): 16[IKE] looking up interface for virtual IP 2abc:123:123:8002:1::12 failed
09-19 09:11:30.805 I/charon (12923): 16[IKE] CHILD_SA android{3} established with SPIs 6413df23_i cda5eef7_o and TS 10.150.240.194/32 2abc:123:123:8002:1::12/128 === 10.150.240.0/23 2abc:123:123::/48
<font color="#660000">09-19 09:11:30.810 I/charon (12923): 16[DMN] setting up TUN device for CHILD_SA android{3}
09-19 09:11:30.810 I/charon (12923): 16[DMN] setting up TUN device failed, no virtual IP found
09-19 09:11:30.810 I/charon (12923): 16[DMN] failed to setup TUN device
09-19 09:11:30.815 I/charon (12923): 16[IKE] peer supports MOBIKE
09-19 09:11:30.830 W/System.err(12923): java.lang.IllegalStateException: Can not perform this action after onSaveInstanceState
09-19 09:11:30.830 W/System.err(12923): at android.app.FragmentManagerImpl.checkStateLoss(FragmentManager.java:1318)
09-19 09:11:30.830 W/System.err(12923): at android.app.FragmentManagerImpl.enqueueAction(FragmentManager.java:1329)
09-19 09:11:30.830 W/System.err(12923): at android.app.BackStackRecord.commitInternal(BackStackRecord.java:595)
09-19 09:11:30.830 W/System.err(12923): at android.app.BackStackRecord.commit(BackStackRecord.java:574)
09-19 09:11:30.830 W/System.err(12923): at org.strongswan.android.ui.ImcStateFragment.updateView(ImcStateFragment.java:176)
09-19 09:11:30.830 W/System.err(12923): at org.strongswan.android.ui.ImcStateFragment.stateChanged(ImcStateFragment.java:152)
09-19 09:11:30.830 W/System.err(12923): at org.strongswan.android.logic.VpnStateService$1.run(VpnStateService.java:213)
09-19 09:11:30.830 W/System.err(12923): at android.os.Handler.handleCallback(Handler.java:730)
09-19 09:11:30.830 W/System.err(12923): at android.os.Handler.dispatchMessage(Handler.java:92)
09-19 09:11:30.830 W/System.err(12923): at android.os.Looper.loop(Looper.java:137)
09-19 09:11:30.830 W/System.err(12923): at android.app.ActivityThread.main(ActivityThread.java:5289)
09-19 09:11:30.830 W/System.err(12923): at java.lang.reflect.Method.invokeNative(Native Method)
09-19 09:11:30.830 W/System.err(12923): at java.lang.reflect.Method.invoke(Method.java:525)
09-19 09:11:30.830 W/System.err(12923): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:739)
09-19 09:11:30.830 W/System.err(12923): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:555)
09-19 09:11:30.830 W/System.err(12923): at dalvik.system.NativeStart.main(Native Method)
</font>09-19 09:11:30.840 I/charon (12923): 00[IKE] deleting IKE_SA android[5] between 192.168.203.96[C=DE, O=test.loc, CN=avalentin-nexus]...X.Y.Z.65[vpn.test.loc]
09-19 09:11:30.840 I/charon (12923): 00[IKE] sending DELETE for IKE_SA android[5]
09-19 09:11:30.845 I/charon (12923): 00[ENC] generating INFORMATIONAL request 2 [ D ]
09-19 09:11:30.845 I/charon (12923): 00[NET] sending packet: from 192.168.203.96[49398] to X.Y.Z.65[4500] (76 bytes)
09-19 09:11:30.845 W/System.err(12923): java.lang.IllegalStateException: Can not perform this action after onSaveInstanceState
09-19 09:11:30.845 W/System.err(12923): at android.app.FragmentManagerImpl.checkStateLoss(FragmentManager.java:1318)
09-19 09:11:30.845 W/System.err(12923): at android.app.FragmentManagerImpl.enqueueAction(FragmentManager.java:1329)
09-19 09:11:30.845 W/System.err(12923): at android.app.BackStackRecord.commitInternal(BackStackRecord.java:595)
09-19 09:11:30.845 W/System.err(12923): at android.app.BackStackRecord.commit(BackStackRecord.java:574)
09-19 09:11:30.845 W/System.err(12923): at org.strongswan.android.ui.ImcStateFragment.updateView(ImcStateFragment.java:176)
09-19 09:11:30.845 W/System.err(12923): at org.strongswan.android.ui.ImcStateFragment.stateChanged(ImcStateFragment.java:152)
09-19 09:11:30.850 W/System.err(12923): at org.strongswan.android.logic.VpnStateService$1.run(VpnStateService.java:213)
09-19 09:11:30.850 W/System.err(12923): at android.os.Handler.handleCallback(Handler.java:730)
09-19 09:11:30.850 W/System.err(12923): at android.os.Handler.dispatchMessage(Handler.java:92)
09-19 09:11:30.850 W/System.err(12923): at android.os.Looper.loop(Looper.java:137)
09-19 09:11:30.850 W/System.err(12923): at android.app.ActivityThread.main(ActivityThread.java:5289)
09-19 09:11:30.850 W/System.err(12923): at java.lang.reflect.Method.invokeNative(Native Method)
09-19 09:11:30.850 W/System.err(12923): at java.lang.reflect.Method.invoke(Method.java:525)
09-19 09:11:30.850 W/System.err(12923): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:739)
09-19 09:11:30.850 W/System.err(12923): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:555)
09-19 09:11:30.850 W/System.err(12923): at dalvik.system.NativeStart.main(Native Method)
09-19 09:11:30.860 W/Netd ( 1952): No subsystem found in netlink event
09-19 09:11:30.860 D/NetlinkEvent( 1952): Unexpected netlink message. type=0x11
09-19 09:11:30.870 D/Vpn ( 2371): setting state=DISCONNECTED, reason=interfaceRemoved
09-19 09:11:30.885 I/CharonVpnService(12923): charon stopped
09-19 09:11:30.885 W/System.err(12923): java.lang.IllegalStateException: Can not perform this action after onSaveInstanceState
09-19 09:11:30.885 W/System.err(12923): at android.app.FragmentManagerImpl.checkStateLoss(FragmentManager.java:1318)
09-19 09:11:30.885 W/System.err(12923): at android.app.FragmentManagerImpl.enqueueAction(FragmentManager.java:1329)
09-19 09:11:30.885 W/System.err(12923): at android.app.BackStackRecord.commitInternal(BackStackRecord.java:595)
09-19 09:11:30.885 W/System.err(12923): at android.app.BackStackRecord.commit(BackStackRecord.java:574)
09-19 09:11:30.885 W/System.err(12923): at org.strongswan.android.ui.ImcStateFragment.updateView(ImcStateFragment.java:176)
09-19 09:11:30.885 W/System.err(12923): at org.strongswan.android.ui.ImcStateFragment.stateChanged(ImcStateFragment.java:152)
09-19 09:11:30.885 W/System.err(12923): at org.strongswan.android.logic.VpnStateService$1.run(VpnStateService.java:213)
09-19 09:11:30.885 W/System.err(12923): at android.os.Handler.handleCallback(Handler.java:730)
09-19 09:11:30.885 W/System.err(12923): at android.os.Handler.dispatchMessage(Handler.java:92)
09-19 09:11:30.885 W/System.err(12923): at android.os.Looper.loop(Looper.java:137)
09-19 09:11:30.885 W/System.err(12923): at android.app.ActivityThread.main(ActivityThread.java:5289)
09-19 09:11:30.885 W/System.err(12923): at java.lang.reflect.Method.invokeNative(Native Method)
09-19 09:11:30.885 W/System.err(12923): at java.lang.reflect.Method.invoke(Method.java:525)
09-19 09:11:30.885 W/System.err(12923): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:739)
09-19 09:11:30.885 W/System.err(12923): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:555)
09-19 09:11:30.885 W/System.err(12923): at dalvik.system.NativeStart.main(Native Method)
09-19 09:11:31.050 W/NetworkManagementSocketTagger(32532): untagSocket(41) failed with errno -22
</pre>
I think it has to do something with this:<br>
<pre><font color="#660000">09-19 09:11:30.810 I/charon (12923): 16[DMN] failed to setup TUN device
09-19 09:11:30.815 I/charon (12923): 16[IKE] peer supports MOBIKE
09-19 09:11:30.830 W/System.err(12923): java.lang.IllegalStateException: Can not perform this action after onSaveInstanceState</font></pre>
But I'm not sure, if the timestamps are accurate enough to tell if
charon is the origin of the error, or perhaps the frontend
[org.strongswan.android.ui.ImcStateFragment.updateView]<br>
Please notice that I use cyanogenmod (based on 4.3). But I do not
think it has to do with it.<br>
<br>
Kind regards,<br>
<br>
André<br>
<br>
P.S.: I left some additional events in the log to indicate the
enviroment.<br>
</body>
</html>