ICE Android connection issue

MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
Hi, I'm new to using ICE and I've been working on a client-side application. I know the server side code is good because the iPhone client my team has developed works with it fine.

The issue I'm having is when I run with the debugger everything works fine (eclipse debugger), but when I run normally I get a ConnectFailedException. It makes me think there is some sort of synchronization issue but I have no clue what it is. Here is the code I use and the stacktrace:
try {
	ic = Ice.Util.initialize();
	proxy = ic.stringToProxy("Echter:default -h serverIP -p 8842");
	Echter.EchterServicePrxHelper.checkedCast(proxy);
	Log.v("GPSNetwork","Connected!");
}catch (ConnectFailedException e){
	Log.e("GPSNetwork","Failed to connect. Application now exiting.");
	Log.e("GPSNetwork",Log.getStackTraceString(e));
	e.printStackTrace();
	System.exit(1);
}catch (Ice.LocalException e) {
	e.printStackTrace();
}

Stack:
03-23 21:47:10.566: ERROR/GPSNetwork(447): Ice.ConnectFailedException
03-23 21:47:10.566: ERROR/GPSNetwork(447): error = 0
03-23 21:47:10.566: ERROR/GPSNetwork(447): at IceInternal.Network.doFinishConnect(Network.java:388)
03-23 21:47:10.566: ERROR/GPSNetwork(447): at IceInternal.TcpTransceiver$1.run(TcpTransceiver.java:35)
03-23 21:47:10.566: ERROR/GPSNetwork(447): at java.lang.Thread.run(Thread.java:935)

Any help at all would be very much appreciated.
«1

Comments

  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    I assume you have set the application permissions correctly to include INTERNET? Do the demos work if you try them outside of the debugger? You could try more tracing (Ice.Trace.Network=2) to get more information. For example, you can check to see if you are actually connecting to the expected address.
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    permissions are set to INTERNET and the demos work. I'm trying to figure out how to change the ice config for use in eclipse.
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    Is this with the emulator or a real device, and what type of network connection are you trying to establish? (ie: LAN/WAN, Wi/FI/3G, etc). Please try the other things I suggested and get back to us with more information.
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    Currently it's using the emulator (we'll be trying it on the G1 Wednesday). The connection is going over the internet. Also, where does the config reside and where is it edited? I can't seem to find it. Thanks for the help by the way.
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    Which config are you talking about precisely?
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    never mind about the config, I figured it out. As for the problem, I need to do some more debugging on it, but I'll post the results tomorrow.
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    Here is what I get with the network tracing set to 2:

    03-25 01:24:31.605: WARN/System.err(355): [ 3/25/09 01:24:31:607 Network: trying to establish tcp connection to 198.145.73.17:8842 ]
    03-25 01:24:31.685: WARN/System.err(355): [ 3/25/09 01:24:31:688 Network: failed to establish tcp connection
    03-25 01:24:31.695: WARN/System.err(355): local address = 0.0.0.0:-1
    03-25 01:24:31.695: WARN/System.err(355): remote address = <not connected>
    03-25 01:24:31.705: WARN/System.err(355): Ice.ConnectFailedException
    03-25 01:24:31.705: WARN/System.err(355): error = 0 ]
    03-25 01:24:31.715: WARN/System.err(355): [ 3/25/09 01:24:31:718 Network: shutting down tcp connection for reading and writing
    03-25 01:24:31.715: WARN/System.err(355): local address = 0.0.0.0:-1
    03-25 01:24:31.715: WARN/System.err(355): remote address = <not connected> ]
    03-25 01:24:32.175: WARN/System.err(355): [ 3/25/09 01:24:32:180 Network: closing tcp connection
    03-25 01:24:32.185: WARN/System.err(355): local address = 0.0.0.0:-1
    03-25 01:24:32.195: WARN/System.err(355): remote address = <not connected> ]
    03-25 01:24:32.255: WARN/System.err(355): [ 3/25/09 01:24:32:261 Network: trying to establish tcp connection to 198.145.73.17:8842 ]
    03-25 01:24:32.285: WARN/System.err(355): [ 3/25/09 01:24:32:282 Network: failed to establish tcp connection
    03-25 01:24:32.285: WARN/System.err(355): local address = 0.0.0.0:-1
    03-25 01:24:32.295: WARN/System.err(355): remote address = <not connected>
    03-25 01:24:32.295: WARN/System.err(355): Ice.ConnectFailedException
    03-25 01:24:32.295: WARN/System.err(355): error = 0 ]
    03-25 01:24:32.335: WARN/System.err(355): [ 3/25/09 01:24:32:331 Network: shutting down tcp connection for reading and writing
    03-25 01:24:32.345: WARN/System.err(355): local address = 0.0.0.0:-1
    03-25 01:24:32.345: WARN/System.err(355): remote address = <not connected> ]

    Odd thing is that it runs just fine with the debugger. Also, one of the guys developing has a really slow laptop that runs it just fine. I will test it on the G1 tomorrow.
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    It looks like the time it takes to start the connection attempt until it reports the connection fails is very short. Could that be the issue? If so, where is that value set?

    -edit: I adjusted the timeout property but it didn't affect anything.
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    What timeout do you have set, and where?
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    Well, default doesn't work so I tried a timeout of 100,000 ms and 10,000 ms and neither worked. it didn't increase or decrease the time given to establish the tcp connection.

    based on the following timestamps, it's only being given less than a tenth of a second to connect.

    03-25 01:24:31.605: WARN/System.err(355): [ 3/25/09 01:24:31:607 Network: trying to establish tcp connection to 198.145.73.17:8842 ]
    03-25 01:24:31.685: WARN/System.err(355): [ 3/25/09 01:24:31:688 Network: failed to establish tcp connection
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    The ConnectFailedException seems to be coming from the checkedCast method since when I do an unchecked cast I don't receive errors (however the connection doesn't get established).

    By the way the timeouts in the prior post get set using the setProperty method on InitializationData and is then used to create the communicator.
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    From looking at the hello android demo it looks like it uses an uncheckedcast rather than a checked one. Why is that?
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    It uses an uncheckedCast so that if server is not running at startup time, the client can still start.
  • bernardbernard Jupiter, FLAdministrators, ZeroC Staff Bernard NormierOrganization: ZeroC, Inc.Project: Ice ZeroC Staff
    Hi Dolan,

    checkedCast and uncheckedCast are quite different:

    - uncheckedCast is a purely local operation: you provide a proxy of one type and Ice manufactures locally a proxy of another type with the same identity and addressing information

    - checkedCast, on the other hand, sends a message to the server (ice_isA) and returns either a proxy of the requested type (if the target object is indeed of that type) or 0 (if it's not) or an Ice exception (if the target object is unreachable).

    So it's not surprising to see uncheckedCast work (it works all the time) and checkedCast fail.

    Cheers,
    Bernard
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    thanks for the explanation. That clears a few things up, but it still doesn't explain why I'm able to connect to the sever while running the debugger, and not when I run my program regularly.
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    I'm afraid that I don't know why. Ice would not report an error, unless that network IP/port was unreachable for some reason. Do the demos all work in the debugger & outside of the debugger to the same host? If they do, then perhaps you could look for differences between your application and the demos.
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    I just modified the hello demo to connect to my server and it won't connect to it (I get the same ConnectFailedException because the TCP connection fails to establish). Normally I'd blame the server code but the iphone client connects to it just fine.
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    So to recap:
    - Android applications work correctly in the debugger but not outside the debugger (although both are running in the emulator)
    - You have not tried on a real device.

    Is this is the case with all machines? Or is it just one single server?

    I think at this point I'd start trying to capture TCP traffic on the emulator host and see exactly what is going on at the TCP level.
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    I tried it out on the device yesterday and the program doesn't work at all (with the debugger as well). It only seems to run on slow machines (I'm guessing on mine the debugger slows things down just enough to allow for connections).

    Do you know how I would go about viewing more in-depth info on TCP traffic on the android?
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    If you are running in the emulator then you can use any tcp analyser on the host itself (such as wireshark).
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    Wireshark results for failed connection:
    TCP connections are getting closed? :-(
    No.     Time        Source                Destination           Protocol Info
         52 38.914867   192.168.0.11          198.145.73.17         TCP      49754 > 8842 [SYN] Seq=0 Win=8192 Len=0 MSS=1460 WS=2
    
    No.     Time        Source                Destination           Protocol Info
         53 39.041894   198.145.73.17         192.168.0.11          TCP      8842 > 49754 [SYN, ACK] Seq=0 Ack=1 Win=5840 Len=0 MSS=1460 WS=6
    
    No.     Time        Source                Destination           Protocol Info
         54 39.041969   192.168.0.11          198.145.73.17         TCP      49754 > 8842 [ACK] Seq=1 Ack=1 Win=17520 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         57 39.190882   198.145.73.17         192.168.0.11          ICEP     Validate connection
    
    No.     Time        Source                Destination           Protocol Info
         58 39.382931   192.168.0.11          198.145.73.17         TCP      49754 > 8842 [ACK] Seq=1 Ack=15 Win=17504 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         59 39.480179   192.168.0.11          198.145.73.17         TCP      49754 > 8842 [FIN, ACK] Seq=1 Ack=15 Win=17504 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         60 39.501492   192.168.0.11          198.145.73.17         TCP      49755 > 8842 [SYN] Seq=0 Win=8192 Len=0 MSS=1460 WS=2
    
    No.     Time        Source                Destination           Protocol Info
         61 39.628903   198.145.73.17         192.168.0.11          TCP      8842 > 49754 [FIN, ACK] Seq=15 Ack=2 Win=5888 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         62 39.628963   192.168.0.11          198.145.73.17         TCP      49754 > 8842 [ACK] Seq=2 Ack=16 Win=17504 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         63 39.646921   198.145.73.17         192.168.0.11          TCP      8842 > 49755 [SYN, ACK] Seq=0 Ack=1 Win=5840 Len=0 MSS=1460 WS=6
    
    No.     Time        Source                Destination           Protocol Info
         64 39.646990   192.168.0.11          198.145.73.17         TCP      49755 > 8842 [ACK] Seq=1 Ack=1 Win=17520 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         65 39.647691   192.168.0.11          198.145.73.17         TCP      49755 > 8842 [FIN, ACK] Seq=1 Ack=1 Win=17520 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         66 39.797916   198.145.73.17         192.168.0.11          ICEP     Validate connection
    
    No.     Time        Source                Destination           Protocol Info
         67 39.797919   198.145.73.17         192.168.0.11          TCP      8842 > 49755 [FIN, ACK] Seq=15 Ack=2 Win=5888 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         68 39.797978   192.168.0.11          198.145.73.17         TCP      49755 > 8842 [RST, ACK] Seq=2 Ack=15 Win=0 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         69 39.798059   192.168.0.11          198.145.73.17         TCP      49755 > 8842 [RST] Seq=2 Win=0 Len=0
    
    

    Here is when I run in the debugger and connection succeeds:
    No.     Time        Source                Destination           Protocol Info
         65 34.210628   192.168.0.11          198.145.73.17         TCP      49814 > 8842 [SYN] Seq=0 Win=8192 Len=0 MSS=1460 WS=2
    
    No.     Time        Source                Destination           Protocol Info
         66 34.344799   198.145.73.17         192.168.0.11          TCP      8842 > 49814 [SYN, ACK] Seq=0 Ack=1 Win=5840 Len=0 MSS=1460 WS=6
    
    No.     Time        Source                Destination           Protocol Info
         67 34.344864   192.168.0.11          198.145.73.17         TCP      49814 > 8842 [ACK] Seq=1 Ack=1 Win=17520 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         68 34.471801   198.145.73.17         192.168.0.11          ICEP     Validate connection
    
    No.     Time        Source                Destination           Protocol Info
         71 34.670850   192.168.0.11          198.145.73.17         TCP      49814 > 8842 [ACK] Seq=1 Ack=15 Win=17504 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         72 34.759287   192.168.0.11          198.145.73.17         ICEP     Request(1): Echter.ice_isA()
    
    No.     Time        Source                Destination           Protocol Info
         74 34.916842   198.145.73.17         192.168.0.11          TCP      8842 > 49814 [ACK] Seq=15 Ack=68 Win=5888 Len=0
    
    No.     Time        Source                Destination           Protocol Info
         75 34.917908   198.145.73.17         192.168.0.11          ICEP     Reply(1): Success
    
    No.     Time        Source                Destination           Protocol Info
         76 35.110880   192.168.0.11          198.145.73.17         TCP      49814 > 8842 [ACK] Seq=68 Ack=41 Win=17480 Len=0
    
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    We just reproduced the issue on a macbook running OSX as well. At this point we've been working on this issue for over a week and we're on the verge of just moving to RMI.
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    I've been trying to reproduce your issue, but at this point haven't had success. I will continue to examine the issue. What hardware and android SDK version are you using?
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    I think we may have found the issue. Apparently the person who installed ICE on the server side installed an old debian package that is version 3.2
    IPhone and G1 are using 3.3. Reason being is because the newer version needs to be built from source. Possibly android was affected and iceTouch wasn't? Anyways, the server team is currently compiling the source and updating to 3.3 and I'll post the results as soon as we get it tested. (Crosses fingers).
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    We updated the server and the same issue still exists.

    Android version 1.1_r1
    and we've tried both with ice 3.3.0 and 3.3.1

    I also made a simple program just to debug this issue and it's having the same error:
    import Ice.Communicator;
    import Ice.ConnectFailedException;
    import Ice.InitializationData;
    import Ice.Properties;
    import android.app.Activity;
    import android.os.Bundle;
    import android.util.Log;
    
    public class NetTest extends Activity {
    	Communicator ic;
        /** Called when the activity is first created. */
    	
        @Override
        public void onCreate(Bundle savedInstanceState) {
            super.onCreate(savedInstanceState);
            setContentView(R.layout.main);
            
            Properties props = Ice.Util.createProperties();
            props.setProperty("Ice.Warn.Connections", "1");
    		props.setProperty("Ice.Trace.Network", "3");
    		props.setProperty("MY.Proxy", "Echter:default -h sturtevant.dyndns.org -p 8842");
    		props.setProperty("MY.Proxy.ConnectionCached", "0");
    		props.setProperty("MY.Proxy.PreferSecure", "0");
    		props.setProperty("MY.Proxy.EndpointSelection", "Ordered");
    		InitializationData id = new InitializationData();
    		id.properties = props;
    		ic = Ice.Util.initialize(id);
    		try {
    			Ice.ObjectPrx proxy = ic.stringToProxy("Echter:default -h sturtevant.dyndns.org -p 8842");
    			Echter.EchterServicePrx echterSrv = Echter.EchterServicePrxHelper.checkedCast(proxy); 
    			Log.v("GPSNetwork","Connected!");
    		}catch (ConnectFailedException e){
    			Log.e("GPSNetwork","Failed to connect. Application now exiting.");
    			System.exit(1);
    		}
        }
        
        @Override
        public void onDestroy(){
        	super.onDestroy();
        	ic.destroy();
        }
    }
    
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    I suspect the issue is due to the use of Android 1.1. We developed and tested Ice for Android with Android 1.0r1 and 1.0r2, since 1.1 wasn't released at the time of development. I'll give 1.1 a try and see what I find out.
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    okay, thanks. Let me know what you find.
  • MaddawgX9MaddawgX9 Member Dolan GishOrganization: WSUVProject: Cardrunner
    By the way, it seems as if I'm getting a TCP error on the android emulator:
    can't set tcp buffer sizes: FileNotFoundException
    I'll look into this some more...
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    As of yet I have not duplicated your error either with Android 1.1 or Android 1.0. However, after reviewing the code I've found something that is suspicious that could cause your failure. I've attached a source code patch for this issue.

    Please apply the patch to the IceAndroid-0.1.0 distribution, and rebuild IceAndroid.jar. You can do that by:
    october:y matthew$ tar xfz ~/Downloads/IceAndroid-0.1.0.tar.gz 
    october:y matthew$ cp ~/android.patch .
    october:y matthew$ ls
    IceAndroid-0.1.0/ android.patch
    october:y matthew$ cd IceAndroid-0.1.0/
    october:IceAndroid-0.1.0 matthew$ ls
    ICE_LICENSE    LICENSE        Makefile.mak   RELEASE_NOTES  certs/         scripts/
    INSTALL        Makefile       README         android/       java/
    october:IceAndroid-0.1.0 matthew$ patch -p0 < ../android.patch 
    patching file ./java/src/IceInternal/TcpAcceptor.java
    patching file ./java/src/IceInternal/TcpConnector.java
    patching file ./java/src/IceInternal/TcpTransceiver.java
    october:IceAndroid-0.1.0 matthew$ cd java
    october:java matthew$ ls
    Makefile      allTests.py*  config/       lib/          test/
    Makefile.mak  build.xml     demo/         src/
    october:java matthew$ ant
    

    After rebuilding, ensure you refresh your Eclipse project to pick up the changes to the .jar file before re-running the application. If you have problems applying the patch, or building please email [email protected], and I'll send you a pre-compiled jar file.

    Unfortunately, because I cannot reproduce the issue its hard to say whether it is the cause of your issue, or whether the attached patch fixes the problem.
  • matthewmatthew NL, CanadaMember Matthew NewhookOrganization: ZeroC, Inc.Project: Internet Communications Engine ✭✭✭
    MaddawgX9 wrote: »
    By the way, it seems as if I'm getting a TCP error on the android emulator:
    can't set tcp buffer sizes: FileNotFoundException
    I'll look into this some more...

    I don't get any problems like that with my emulator. What hardware platform are you using?
Sign In or Register to comment.