Network timeout on Android

Discuss any general programming issues here
User avatar
airsoftsoftwair
Posts: 3038
Joined: Fri Feb 12, 2010 2:33 pm
Location: Germany
Contact:

Re: Network timeout on Android

Post by airsoftsoftwair » Tue Sep 27, 2016 6:00 pm

Ok, next log please...

zylesea
Posts: 200
Joined: Tue Feb 16, 2010 12:50 am
Location: Westfalen/Germany
Contact:

Re: Network timeout on Android

Post by zylesea » Tue Sep 27, 2016 11:06 pm

There it is:

Code: Select all

I/LogTag  ( 3759): And Action!
I/LogTag  ( 3759): 
I/LogTag  ( 3759): *** NEW NEW OPEN CONNECTION: www.airsoftsoftwair.de
I/LogTag  ( 3759): *** GETHOSTBYNAME FOR www.airsoftsoftwair.de
I/LogTag  ( 3759): *** INET_PTON: 1
I/LogTag  ( 3759): SIZEOF: 4 16 16
I/LogTag  ( 3759): *** TRYING TO CONNECT
I/LogTag  ( 3759): *** HOLDING THE LINE
I/LogTag  ( 3759): *** APP_CMD_WINDOW_RESIZED
I/LogTag  ( 3759): *** GOT0: 0
I/LogTag  ( 3759): *** SEND REQUEST: GET /images/products/hollywood/47_shot1.jpg HTTP/1.1
I/LogTag  ( 3759): TE: trailers
I/LogTag  ( 3759): Connection: close, TE
I/LogTag  ( 3759): Host: www.airsoftsoftwair.de
I/LogTag  ( 3759): User-Agent: Hollywood 6.1
I/LogTag  ( 3759): 
I/LogTag  ( 3759): *** GOT1: 0
I/LogTag  ( 3759): *** GETTING STATUS
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** TAKEN: -1
I/LogTag  ( 3759): *** ERRNO: 11
(...2000 lines removed...)
I/LogTag  ( 3759): *** TAKEN: 1440
I/LogTag  ( 3759): *** RECV: 0 GOT: 1440
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1440
I/LogTag  ( 3759): *** GOT3: 0 STATUS: 200
I/LogTag  ( 3759): *** GETTING HTTP HEADERS
I/LogTag  ( 3759): *** GET NEXT LINE
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1423
I/LogTag  ( 3759): *** ERROR: 0 GOT LINE: Date: Tue, 27 Sep 2016 19:37:22 GMT
I/LogTag  ( 3759): *** GET NEXT LINE
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1386
I/LogTag  ( 3759): *** ERROR: 0 GOT LINE: Content-Type: image/jpeg
I/LogTag  ( 3759): *** GET NEXT LINE
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1360
I/LogTag  ( 3759): *** ERROR: 0 GOT LINE: Content-Length: 142147
I/LogTag  ( 3759): *** GET NEXT LINE
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1336
I/LogTag  ( 3759): *** ERROR: 0 GOT LINE: Connection: close
I/LogTag  ( 3759): *** GET NEXT LINE
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1317
I/LogTag  ( 3759): *** ERROR: 0 GOT LINE: Server: Apache
I/LogTag  ( 3759): *** GET NEXT LINE
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1301
I/LogTag  ( 3759): *** ERROR: 0 GOT LINE: Last-Modified: Fri, 23 Apr 2010 12:52:22 GMT
I/LogTag  ( 3759): *** GET NEXT LINE
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1255
I/LogTag  ( 3759): *** ERROR: 0 GOT LINE: ETag: "1be54d-22b43-484e6e5f18d80"
I/LogTag  ( 3759): *** GET NEXT LINE
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1219
I/LogTag  ( 3759): *** ERROR: 0 GOT LINE: Accept-Ranges: bytes
I/LogTag  ( 3759): *** GET NEXT LINE
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1197
I/LogTag  ( 3759): *** ERROR: 0 GOT LINE: 
I/LogTag  ( 3759): *** GOT4: 0
I/LogTag  ( 3759): *** NOW DOWNLOADING 142147 BYTES
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1195
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** TAKEN: 4320
I/LogTag  ( 3759): *** RECV: 0 GOT: 4320
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 4320
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** TAKEN: 1440
I/LogTag  ( 3759): *** RECV: 0 GOT: 1440
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1440
I/LogTag  ( 3759): *** BUFFER_GET
I/LogTag  ( 3759): *** TAKEN: -1
I/LogTag  ( 3759): *** ERRNO: 11
(... 4000 lines removed ...)
I/LogTag  ( 3759): *** TAKEN: 1272
I/LogTag  ( 3759): *** RECV: 0 GOT: 1272
I/LogTag  ( 3759): *** RETURN --> ERROR: 0 COUNT: 1272
I/LogTag  ( 3759): *** GOT5: 0
I/threaded_app( 3759): New input event: type=2
I/threaded_app( 3759): New input event: type=2
I/Finsky  ( 1520): [135] com.google.android.finsky.c.e.run(1154): Replicating app states via AMAS.
W/ActivityManager(  464): Activity pause timeout for ActivityRecord{a923a6d u0 com.airsoftsoftwair.hollywood/.HollywoodActivity t67 f}
I/InputDispatcher(  464): Dropping event because there is no touchable window at (225, 589).
I/Finsky  ( 1520): [1] com.google.android.finsky.c.c.a(316): Completed 1 account content syncs with 1 successful.
I/Finsky  ( 1520): [1] com.google.android.finsky.services.j.a(149): Installation state replication succeeded.
I/ActivityManager(  464): Killing 3516:com.google.android.gms.feedback/u0a8 (adj 15): empty #17
I/LogTag  ( 3759): *** APP_CMD_LOST_FOCUS
I/LogTag  ( 3759): *** APP_CMD_PAUSE
W/OpenGLRenderer( 1028): Incorrectly called buildLayer on View: ShortcutAndWidgetContainer, destroying layer...
W/art     ( 3804): Native thread exiting without having called DetachCurrentThread (maybe it's going to use a pthread_key_create destructor?): Thread[30,tid=3895,Native,Thread*=0x79734158,peer=0x4229c8e0,"CL-1637930968"]
W/art     ( 3804): Native thread exiting without having called DetachCurrentThread (maybe it's going to use a pthread_key_create destructor?): Thread[28,tid=3903,Native,Thread*=0x78eb0cf8,peer=0x4229c820,"CL-2032504256"]
W/ResourceType(  679): No package identifier when getting value for resource number 0x00000000
W/PackageManager(  679): Failure retrieving resources for com.airsoftsoftwair.hollywood: Resource ID #0x0
I/LogTag  ( 3759): *** APP_CMD_STOP
I/LogTag  ( 3759): *** APP_CMD_TERM_WINDOW
I/Process ( 3759): Sending signal. PID: 3759 SIG: 9
I/WindowState(  464): WIN DEATH: Window{63ca9c6 u0 com.airsoftsoftwair.hollywood/com.airsoftsoftwair.hollywood.HollywoodActivity}
I/ActivityManager(  464): Process com.airsoftsoftwair.hollywood (pid 3759) has died      

User avatar
airsoftsoftwair
Posts: 3038
Joined: Fri Feb 12, 2010 2:33 pm
Location: Germany
Contact:

Re: Network timeout on Android

Post by airsoftsoftwair » Tue Sep 27, 2016 11:58 pm

Almost there now (hopefully)... please try the new build and post the log...

zylesea
Posts: 200
Joined: Tue Feb 16, 2010 12:50 am
Location: Westfalen/Germany
Contact:

Re: Network timeout on Android

Post by zylesea » Wed Sep 28, 2016 9:56 pm

Debug output is little now:

Code: Select all

I/LogTag  (11304): And Action!
I/LogTag  (11304):
I/LogTag  (11304): *** NEW NEW OPEN CONNECTION: www.airsoftsoftwair.de
I/LogTag  (11304): *** GETHOSTBYNAME FOR www.airsoftsoftwair.de
I/DownloadManagerWrapper(  903): onReceive() : Charging = true
I/LogTag  (11304): *** GOT0: 1410
I/LogTag  (11304): *** APP_CMD_WINDOW_RESIZED
V/WindowManager(  464): not Base app: Adding window Window{21e82a70 u0 com.airsoftsoftwair.hollywood/com.airsoftsoftwair
.hollywood.HollywoodActivity} at 6 of 12
I/LogTag  (11304): *** APP_CMD_LOST_FOCUS
E/WifiStateMachine(  464): WifiStateMachine CMD_START_SCAN source -2 txSuccessRate=0,54 rxSuccessRate=0,03 targetRoamBSS
ID=c8:0e:14:fa:33:72 RSSI=-87
I/LogTag  (11304): *** APP_CMD_GAINED_FOCUS
W/InputMethodManagerService(  464): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMeth
odClient$Stub$Proxy@4016521 attribute=null, token = android.os.BinderProxy@36f55872
W/ActivityManager(  464): Activity pause timeout for ActivityRecord{2ff4bac2 u0 com.airsoftsoftwair.hollywood/.Hollywood
Activity t73 f}
I/LogTag  (11304): *** APP_CMD_LOST_FOCUS
I/LogTag  (11304): *** APP_CMD_PAUSE
W/ResourceType(  679): No package identifier when getting value for resource number 0x00000000
W/PackageManager(  679): Failure retrieving resources for com.airsoftsoftwair.hollywood: Resource ID #0x0
D/ConnectivityService(  464): updateNetworkScore for NetworkAgentInfo [WIFI () - 101] to 52
D/ConnectivityService(  464): rematching NetworkAgentInfo [WIFI () - 101]
D/ConnectivityService(  464): Network NetworkAgentInfo [WIFI () - 101] was already satisfying request 1. No change.
D/ConnectivityService(  464): notifyType AVAILABLE for NetworkAgentInfo [WIFI () - 101]
D/ConnectivityManager.CallbackHandler(  679): CM callback handler got msg 524290
D/ConnectivityManager.CallbackHandler( 7482): CM callback handler got msg 524290
D/ConnectivityManager.CallbackHandler( 3980): CM callback handler got msg 524290
D/ConnectivityManager.CallbackHandler( 1305): CM callback handler got msg 524290
D/ConnectivityManager.CallbackHandler( 9693): CM callback handler got msg 524290
I/LogTag  (11304): *** APP_CMD_STOP
I/LogTag  (11304): *** APP_CMD_TERM_WINDOW
I/Process (11304): Sending signal. PID: 11304 SIG: 9
I/WindowState(  464): WIN DEATH: Window{19594c3 u0 com.airsoftsoftwair.hollywood/com.airsoftsoftwair.hollywood.Hollywood
Activity}
I/ActivityManager(  464): Process com.airsoftsoftwair.hollywood (pid 11304) has died  

User avatar
airsoftsoftwair
Posts: 3038
Joined: Fri Feb 12, 2010 2:33 pm
Location: Germany
Contact:

Re: Network timeout on Android

Post by airsoftsoftwair » Wed Sep 28, 2016 10:33 pm

Hmm, really? That is weird. This means it cannot connect but I didn't change anything in the code related to making connections. Maybe there was some temporary problem with airsoftsoftwair.de or your ISP. Can you try again to see if it really doesn't go any further than this?

zylesea
Posts: 200
Joined: Tue Feb 16, 2010 12:50 am
Location: Westfalen/Germany
Contact:

Re: Network timeout on Android

Post by zylesea » Thu Sep 29, 2016 9:58 am

Indeed something was wrong. I did a new test. The script times out after about 2 minutes with the message "Remote Server has closed teh connection!". Because of running that long, the debugfile increased to quite a size - 329 000 lines (about 23 MB) which is too much for my Amiga/MorphOS editors (GoldED does not show the entire file, Scribble loads it but runs out of mem (1.5 GB) then). The Windows Editor can handle it though and here is the start and the end of the debug file. Due to its massive size I was only able to bluntly cut away most lines w/o checking the actual content.

Code: Select all

I/LogTag  (15394): *** NEW NEW OPEN CONNECTION: www.airsoftsoftwair.de

I/LogTag  (15394): *** GETHOSTBYNAME FOR www.airsoftsoftwair.de

I/LogTag  (15394): *** INET_PTON: 1

I/LogTag  (15394): SIZEOF: 4 16 16

I/LogTag  (15394): *** TRYING TO CONNECT

I/LogTag  (15394): *** HOLDING THE LINE

I/LogTag  (15394): *** APP_CMD_WINDOW_RESIZED

I/LogTag  (15394): *** GOT0: 0

I/LogTag  (15394): REQUEST1: GET /images/products/hollywood/47_shot1.jpg HTTP/1.1


I/LogTag  (15394): 

I/LogTag  (15394): REQUEST3: TE: trailers


I/LogTag  (15394): Connection: close, TE


I/LogTag  (15394): Host: www.airsoftsoftwair.de


I/LogTag  (15394): User-Agent: Hollywood 6.1


I/LogTag  (15394): 


I/LogTag  (15394): 

I/LogTag  (15394): POST: 0 UPLOAD: 0

I/LogTag  (15394): *** GETTING STATUS

I/LogTag  (15394): *** BUFFER_GET

I/LogTag  (15394): *** TAKEN: -1

I/LogTag  (15394): *** ERRNO: 11

I/LogTag  (15394): *** TAKEN: -1

I/LogTag  (15394): *** ERRNO: 11

(...cut awy about 329000 lines!...)

I/LogTag  (15394): *** TAKEN: -1

I/LogTag  (15394): *** ERRNO: 11

I/LogTag  (15394): *** GOT3: 1423 STATUS: -1

V/WindowManager(  464): not Base app: Adding window Window{3b1a4aaa u0 com.airsoftsoftwair.hollywood/com.airsoftsoftwair.hollywood.HollywoodActivity} at 6 of 12

I/LogTag  (15394): *** APP_CMD_LOST_FOCUS

D/ConnectivityService(  464): updateNetworkScore for NetworkAgentInfo [WIFI () - 101] to 51

D/ConnectivityService(  464): rematching NetworkAgentInfo [WIFI () - 101]

D/ConnectivityService(  464): Network NetworkAgentInfo [WIFI () - 101] was already satisfying request 1. No change.

D/ConnectivityService(  464): notifyType AVAILABLE for NetworkAgentInfo [WIFI () - 101]

D/ConnectivityManager.CallbackHandler(  679): CM callback handler got msg 524290

D/ConnectivityManager.CallbackHandler( 1305): CM callback handler got msg 524290

D/ConnectivityManager.CallbackHandler( 3980): CM callback handler got msg 524290

D/ConnectivityManager.CallbackHandler(16260): CM callback handler got msg 524290

I/LogTag  (15394): *** APP_CMD_GAINED_FOCUS

W/InputMethodManagerService(  464): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@ad83177 attribute=null, token = android.os.BinderProxy@1fd5992

W/ActivityManager(  464): Activity pause timeout for ActivityRecord{231c33e2 u0 com.airsoftsoftwair.hollywood/.HollywoodActivity t76 f}

I/LogTag  (15394): *** APP_CMD_LOST_FOCUS

I/LogTag  (15394): *** APP_CMD_PAUSE

I/ActivityManager(  464): Killing 15025:com.google.android.talk/u0a43 (adj 15): empty #17

W/OpenGLRenderer( 1028): Incorrectly called buildLayer on View: ShortcutAndWidgetContainer, destroying layer...

W/ResourceType(  679): No package identifier when getting value for resource number 0x00000000

W/PackageManager(  679): Failure retrieving resources for com.airsoftsoftwair.hollywood: Resource ID #0x0

I/LogTag  (15394): *** APP_CMD_TERM_WINDOW

I/Process (15394): Sending signal. PID: 15394 SIG: 9

I/WindowState(  464): WIN DEATH: Window{2315cf63 u0 com.airsoftsoftwair.hollywood/com.airsoftsoftwair.hollywood.HollywoodActivity}

I/ActivityManager(  464): Process com.airsoftsoftwair.hollywood (pid 15394) has died   

User avatar
airsoftsoftwair
Posts: 3038
Joined: Fri Feb 12, 2010 2:33 pm
Location: Germany
Contact:

Re: Network timeout on Android

Post by airsoftsoftwair » Thu Sep 29, 2016 5:05 pm

Ok, thanks, next log please :)

zylesea
Posts: 200
Joined: Tue Feb 16, 2010 12:50 am
Location: Westfalen/Germany
Contact:

Re: Network timeout on Android

Post by zylesea » Fri Sep 30, 2016 2:32 pm

Here it is:

Code: Select all

I/LogTag  ( 4451): And Action!
I/LogTag  ( 4451): 
I/LogTag  ( 4451): *** NEW NEW OPEN CONNECTION: www.airsoftsoftwair.de
I/LogTag  ( 4451): *** GETHOSTBYNAME FOR www.airsoftsoftwair.de
I/LogTag  ( 4451): *** INET_PTON: 1
I/LogTag  ( 4451): SIZEOF: 4 16 16
I/LogTag  ( 4451): *** TRYING TO CONNECT
I/LogTag  ( 4451): *** HOLDING THE LINE
I/LogTag  ( 4451): *** APP_CMD_WINDOW_RESIZED
I/LogTag  ( 4451): *** GOT0: 0
I/LogTag  ( 4451): NEW REQUEST1: GET /images/products/hollywood/47_shot1.jpg HTTP/1.1
I/LogTag  ( 4451): REQUEST3: TE: trailers
I/LogTag  ( 4451): Connection: close, TE
I/LogTag  ( 4451): Host: www.airsoftsoftwair.de
I/LogTag  ( 4451): User-Agent: Hollywood 6.1
I/LogTag  ( 4451): POST: 0 UPLOAD: 0
I/LogTag  ( 4451): *** GETTING STATUS
I/LogTag  ( 4451): *** BUFFER_GET
I/LogTag  ( 4451): *** TAKEN: -1
I/LogTag  ( 4451): *** ERRNO: 11
I/LogTag  ( 4451): *** NEW WAITFD --- BLOCK: 0 TOTAL: 0 START: 1475236280.574
I/LogTag  ( 4451): *** NOW RUNNING SELECT WITH TIMEOUT: 10 0
W/IcingInternalCorpora( 1242): getNumBytesRead when not calculated.
I/Icing   ( 1242): Usage reports 0 indexed 0 rejected 0 imm upload false
I/Icing   ( 1242): Usage reports 0 indexed 0 rejected 0 imm upload false
I/Icing   ( 1242): Usage reports 0 indexed 0 rejected 0 imm upload false
I/Icing   ( 1242): Usage reports 0 indexed 0 rejected 0 imm upload false
I/art     (  470): Explicit concurrent mark sweep GC freed 34538(1596KB) AllocSpace objects, 5(80KB) LOS objects, 33% free, 19MB/29MB, paused 1.952ms total 98.828ms
I/Icing   ( 1242): Usage reports 0 indexed 0 rejected 0 imm upload false
I/Icing   ( 1242): Usage reports 0 indexed 0 rejected 0 imm upload false
I/Icing   ( 1242): Usage reports 0 indexed 0 rejected 0 imm upload false
I/LogTag  ( 4451): *** RETURN FROM SELECT WITH: 0 11 ---- THIS TOOK: 10 3471
I/LogTag  ( 4451): *** EXIT: 0
I/LogTag  ( 4451): *** RECV: -1 GOT: 0
I/LogTag  ( 4451): *** RETURN --> ERROR: -1 COUNT: 0
I/LogTag  ( 4451): *** GOT IO_TIMEOUT
I/LogTag  ( 4451): *** NETWORK TIMEOUT THRESHOLD REACHED (10000) -- ERRORING
I/LogTag  ( 4451): *** GOT3: 1422 STATUS: -1
V/WindowManager(  470): not Base app: Adding window Window{bb78e96 u0 com.airsoftsoftwair.hollywood/com.airsoftsoftwair.hollywood.HollywoodActivity} at 4 of 9
I/LogTag  ( 4451): *** APP_CMD_LOST_FOCUS
I/LogTag  ( 4451): *** APP_CMD_GAINED_FOCUS
W/InputMethodManagerService(  470): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@16d7c0b3 attribute=null, token = android.os.BinderProxy@39167c3f
W/ActivityManager(  470): Activity pause timeout for ActivityRecord{824a14f u0 com.airsoftsoftwair.hollywood/.HollywoodActivity t16 f}
I/DownloadManagerWrapper(  885): onReceive() : Charging = true
I/ActivityManager(  470): Killing 2692:com.android.providers.calendar/u0a1 (adj 15): empty #17
I/LogTag  ( 4451): *** APP_CMD_LOST_FOCUS
I/LogTag  ( 4451): *** APP_CMD_PAUSE
D/ConnectivityService(  470): updateNetworkScore for NetworkAgentInfo [WIFI () - 100] to 51
D/ConnectivityService(  470): rematching NetworkAgentInfo [WIFI () - 100]
D/ConnectivityService(  470): Network NetworkAgentInfo [WIFI () - 100] was already satisfying request 1. No change.
D/ConnectivityService(  470): notifyType AVAILABLE for NetworkAgentInfo [WIFI () - 100]
D/ConnectivityManager.CallbackHandler(  660): CM callback handler got msg 524290
D/ConnectivityManager.CallbackHandler( 1242): CM callback handler got msg 524290
D/ConnectivityManager.CallbackHandler( 2350): CM callback handler got msg 524290
W/ResourceType(  660): No package identifier when getting value for resource number 0x00000000
W/PackageManager(  660): Failure retrieving resources for com.airsoftsoftwair.hollywood: Resource ID #0x0
I/LogTag  ( 4451): *** APP_CMD_STOP
I/LogTag  ( 4451): *** APP_CMD_TERM_WINDOW
I/Process ( 4451): Sending signal. PID: 4451 SIG: 9
I/WindowState(  470): WIN DEATH: Window{28490c u0 com.airsoftsoftwair.hollywood/com.airsoftsoftwair.hollywood.HollywoodActivity}
I/ActivityManager(  470): Process com.airsoftsoftwair.hollywood (pid 4451) has died   

User avatar
airsoftsoftwair
Posts: 3038
Joined: Fri Feb 12, 2010 2:33 pm
Location: Germany
Contact:

Re: Network timeout on Android

Post by airsoftsoftwair » Fri Sep 30, 2016 5:21 pm

Ok, I've just uploaded a new version which might fix the issue. It doesn't have any more debug output so you don't need to post a log. Just tell me if it works correctly now :)

zylesea
Posts: 200
Joined: Tue Feb 16, 2010 12:50 am
Location: Westfalen/Germany
Contact:

Re: Network timeout on Android

Post by zylesea » Fri Sep 30, 2016 9:23 pm

It works. The script loads the image.
Great - thumbs up!

Post Reply