search

wei-spring / codenameone

Automatically exported from code.google.com/p/codenameone
0 stars 0 forks source link

Sample program to crash ios.newVM #1304

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
The first time you run one of my apps it has to obtain data. this is normally 
done over the network but can also be done with a file copied to the device. 
Either way if the dataset is a small one, my apps work. However larger datasets 
consistently crash the new VM.

In trying to narrow down the problem and create a test case I have come to the 
conclusion that it is not a particular operation that is causing the crash but 
the load.

The sample program attached will read lines from a file and run them through 
your CSVParser. It crashes before completion. In order to run this app you will 
need to set the property ios.fileSharingEnabled to true and you will need to 
copy the sample data file to the app on your device using iTunes.

This app runs fine on the old VM, it also runs a lot faster on the old VM, it 
takes about 18 seconds to complete. On the new VM it takes 38 seconds to crash 
without completing.

This initial data load is key to my apps and so I can't really test my apps at 
all on the new VM because I can't get any data to them.

I have attached the sample program, the data file you will need to run the 
program and the crash log I received from my iPod.

Original issue reported on code.google.com by mwarn...@readerware.com on 23 Jan 2015 at 10:53

Attachments:

GoogleCodeExporter commented 9 years ago

Original comment by st...@weblite.ca on 27 Jan 2015 at 11:46

GoogleCodeExporter commented 9 years ago 
I tried this example out on the Xcode iOS Simulator (iPhone 6, iOS 8.1) and it 
seemed to work fine on multiple runs.  Haven't built for device, but Simulator 
should be accurate in this case.  There have been a few other fixes that may 
have already fixed this.  Reopen this issue if you are still having an issue 
after the next update.

Original comment by st...@weblite.ca on 28 Jan 2015 at 12:41

GoogleCodeExporter commented 9 years ago 
I don't know how to reopen an issue but hopefully you will see this.

I rebuilt my test app and ran it on a device and it ran to completion which is 
a first. So something has changed. However is hasn't solved my basic problem, 
none of my apps run on an actual device.

I extracted some of the code from my app to produce this test case. This test 
case now works so things are getting better, but I still have problems in the 
full app.

I made one change to my test app and have attached the new version. The 
original ran the test once and stopped because it never made it that far. The 
new version will display a Run Again button when the test completes. Running 
the test app on a device, it completes the test the first time I run it but it 
crashes if I rerun the test.

On running in the Xcode simulator, I can run my full app in the simulator and 
it will load the biggest datasets without a problem. I take the source code you 
provide, build it in Xcode and run my app in the simulator, everything works. 
The same app crashes every time on the device. So I do think you need to run 
this on the device if the new version still works in the simulator.

Thanks

Original comment by mwarn...@readerware.com on 28 Jan 2015 at 10:50

Attachments:

GoogleCodeExporter commented 9 years ago

Original comment by steve.ha...@codenameone.com on 28 Jan 2015 at 3:09

GoogleCodeExporter commented 9 years ago 
Interesting.  I have reproduced the problem on an iPhone4S iOS 8.1.

"""
Exception Type:  EXC_RESOURCE
Exception Subtype: WAKEUPS
Exception Message: (Limit 150/sec) Observed 164/sec over 300 secs
Triggered by Thread:  5
"""

It looks like it is exceeding some resource limits... looking into this further.

Original comment by steve.ha...@codenameone.com on 28 Jan 2015 at 6:29

GoogleCodeExporter commented 9 years ago 
This thread appears to speak to the issue:
http://stackoverflow.com/a/26123141/2935174

"""
Your app is sending a wakeup command to a particular thread in the app quite 
often - apparently an average of 206 times a second. Background threads in iOS 
8 have a hard limit on how many times you can run a sleep/wake cycle on each 
thread per second, and having a high count here is usually an indication that 
something is wrong / inefficient in your thread management.
"""

Original comment by steve.ha...@codenameone.com on 28 Jan 2015 at 6:46

GoogleCodeExporter commented 9 years ago 
This might be helpful also:
http://www.reddit.com/r/SchoolIdolFestival/comments/2nt4ly/a_fix_for_ios_8_lag_i
ssues/

He suggests catching this exception... didn't know that was possible.

Original comment by steve.ha...@codenameone.com on 28 Jan 2015 at 6:57

GoogleCodeExporter commented 9 years ago 
Scratch that previous link... it is a fix that requires jail break....  not for 
us.

Original comment by steve.ha...@codenameone.com on 28 Jan 2015 at 7:01

GoogleCodeExporter commented 9 years ago 
I don't see how this is me though. This test app is pretty straightforward. I 
am starting a new thread when you click on Start to do the processing. 
Obviously I don't want to do this on the EDT.

I am using Display.getInstance().callSerially to update the progress on the 
EDT. Initially I was doing this on every read, even on the old VM that caused 
problems. So I changed it so that I only report progress every 100 records. If 
you are running the app on the device you can see the progress update and it is 
happening slowly, there is an update every few seconds. So I don't think the 
progress call backs are causing this.

I updated my test app here to take out the progress report so that it just 
displays the start and end messages. It still crashes so I don't think it is 
the call  back.

I only have the two threads, I think the code is very basic. I don't know what 
would cause a wakeup command to be issued, I can't see how that is coming from 
my code.

Is the new VM creating additional threads, how does garbage collection work, 
could it be waking up threads? I do think this is related to garbage 
collection, this app is reading a bunch of records and parsing them using your 
CSVParser class. That is probably causing a lot of memory to be used and then 
garbage collected.

Original comment by mwarn...@readerware.com on 28 Jan 2015 at 7:27

GoogleCodeExporter commented 9 years ago 
The comments I posted aren't directions to you.  They're notes on the issue.  
I'm referring to thread wake-ups, not callbacks in your code.

Original comment by steve.ha...@codenameone.com on 28 Jan 2015 at 7:32

GoogleCodeExporter commented 9 years ago 
Notes after running some more tests:

This problem definitely *only* occurs on the new VM.  I have tested on the old 
VM (built with Xcode 6.1, running iPhone 4S with iOS 8.1), and I can run the 
test over and over again (I've just done it 10 times consecutively with no 
problem).

I have added break points and logging in the old VM to track all calls to 
pthread_cond_signal and pthread_cond_broadcast, and there aren't nearly enough 
of those to go over the limit posted.

Conclusions:

1. Issue is New VM specific.
2. The error message is either misleading (i.e. it didn't actually crash for 
waking a thread too often), or there are wakes originating from things other 
than pthread_cond_signal and pthread_cond_broadcast.

I will now work on putting together some symbolicated crash reports and try to 
put them through Apple support to see if they can offer any clues.

Original comment by steve.ha...@codenameone.com on 30 Jan 2015 at 11:16

GoogleCodeExporter commented 9 years ago 
I'm getting the crash only on the third run of the app and I don't see the 
error you guys are mentioning.

FYI the old VM didn't implement threading/contention correctly so its bound to 
act differently. We have quite a few open bugs on that fact.

Original comment by shai.almog on 31 Jan 2015 at 12:24

GoogleCodeExporter commented 9 years ago 
"I'm getting the crash only on the third run"

I suspect that your device is probably just faster than mine so you are able to 
accomplish more before iOS closes the door.   I'm running on a 4S.

Original comment by steve.ha...@codenameone.com on 31 Jan 2015 at 2:28

GoogleCodeExporter commented 9 years ago 
But I'm still not seeing that error. Where is it shown?

Original comment by shai.almog on 31 Jan 2015 at 3:50

GoogleCodeExporter commented 9 years ago 
I think it was in the device log.  But, maybe the changes you pushed today have 
changed things.  I'll re-run and see if I get the same error.  Will let you 
know.

Original comment by steve.ha...@codenameone.com on 31 Jan 2015 at 3:58

GoogleCodeExporter commented 9 years ago 
I did some more testing here. I rebuilt my app so it has the latest server 
code. On the device I have been using all along, it now crashes the third time 
I run the test. So things are getting better but it is still crashing.

I tried on three different iOS devices and I am seeing very different results 
on each device.

Before running a test I clear out the device logs using Xcode, then after the 
test I collect the logs from the device. I often have multiple logs on the 
device from the one test.

Device by device:

iPod Touch (5th generation) Model MD723LL/A iOS 8.1.2 (12B440)
Test run 3 times, craashed 3rd time around row 200
3 logs on device attached files begin with ipod5.

iPad Mini (Model A1432) Model MD528LL/A iOS 8.1.3 (12B466)
Test run 2 times, crashed 2nd time around row 500
2 logs on device attached files begin with iPad.

iPod Touch Model ME178LL/A iOS 6.1.6 (10B500)
Test crashed first time around row 900
1 log on device attached file begins with ipod41.

Original comment by mwarn...@readerware.com on 31 Jan 2015 at 6:06

Attachments:

GoogleCodeExporter commented 9 years ago 
I think that if you will add a single thread.sleep(1) for every 200 rows you 
will solve the issue.

You effectively have an infinite loop which allocates a lot of memory and 
blocks gc. Its possible there is a deeper issue here but our GC is normally 
very shallow and so it lets some stuff stay after every iteration. Since its 
concurrent it will not stop your thread and will wait for it to sleep or yield 
(which it doesn't) so when memory warnings start firing in, it doesn't have the 
time to cleanup.

Original comment by shai.almog on 31 Jan 2015 at 6:17

GoogleCodeExporter commented 9 years ago 
With that change (Thread.sleep(1) after every 100 iterations), it seems to be 
working ok so far.  I've gone through 5 runs and the memory is stable and 
relatively constant.

Original comment by steve.ha...@codenameone.com on 31 Jan 2015 at 6:49

GoogleCodeExporter commented 9 years ago 
With this change the test app works here too.

Unfortunately it has done nothing for my real app. That is still crashing and 
in same place. It is not getting any further with the sleep. I tried increasing 
the frequency and duration of the sleep but that is not helping either.

I guess I need to come up with a new test case.

Original comment by mwarn...@readerware.com on 31 Jan 2015 at 7:36

GoogleCodeExporter commented 9 years ago 
Can you attach the crash reports with the sleep?
I want to see if you are getting out of memory crashes or the EXC_RESOURCE 
crashes as Steve described.
I was unable to get the EXC_RESOURCE crashes.

Original comment by shai.almog on 31 Jan 2015 at 7:53

GoogleCodeExporter commented 9 years ago 
Attached

Original comment by mwarn...@readerware.com on 31 Jan 2015 at 8:09

Attachments:

GoogleCodeExporter commented 9 years ago 
OK its an out of memory crash (used roughly 344MB). I've got some fixes going 
in tomorrow which might help alleviate this issue and won't require sleep. Make 
sure you don't have code in your app that runs in an infinite loop and never 
sleeps or yields... This would be very bad on the old VM but could crash the 
current one since it would effectively block the GC.

Original comment by shai.almog on 31 Jan 2015 at 8:17

GoogleCodeExporter commented 9 years ago 
I had added a sleep(1) after every 100 rows and that did not seem to make any 
difference. I just added a yield() after every row and my app got a lot 
further, almost made it through the file. It did not seem to be impacting 
performance.

Let me know when the new version is up and I will see where things stand. It is 
getting close.

I attached the latest logs from the yield run

Original comment by mwarn...@readerware.com on 31 Jan 2015 at 8:52

Attachments:

GoogleCodeExporter commented 9 years ago 
These changes are now online and should also boost performance.

Original comment by shai.almog on 1 Feb 2015 at 7:36

GoogleCodeExporter commented 9 years ago 
There is an improvement but I still cannot complete the load in my real app. 
This time I ended up with 1,668 rows in the database, there are 1742 rows in 
that file.

It also seems that things are more inconsistent than before. It always used to 
fail at the same point, now it varies quite a bit.

Latest crash logs attached.

Original comment by mwarn...@readerware.com on 1 Feb 2015 at 3:43

Attachments:

GoogleCodeExporter commented 9 years ago 
We've made another improvement. We also made significant performance 
improvements which should make the performance as fast or faster than the old 
VM. Please check now to see if this improves the situation.

Original comment by shai.almog on 2 Feb 2015 at 8:49

GoogleCodeExporter commented 9 years ago 
Just tried building the test with the latest changes, and it crashes on 
startup.  Screenshot from Xcode attached.  It's an EXC_BAD_ACCESS inside the 
monitorEnter.  I'll leave this one for you Shai as it likely relates to the GC.

Original comment by st...@weblite.ca on 2 Feb 2015 at 9:37

Attachments:

GoogleCodeExporter commented 9 years ago 
Having the same problem here, I can't run anything, even the simplest test app 
crashes. I was going to leave it a couple of hours and try again. I figured 
everybody would being having problems and you would quickly get it.

Original comment by mwarn...@readerware.com on 2 Feb 2015 at 9:52

GoogleCodeExporter commented 9 years ago 
This should be solved now.

Original comment by shai.almog on 3 Feb 2015 at 4:57

GoogleCodeExporter commented 9 years ago 
Confirmed.  This new problem is fixed.  I just tried running the test without 
the Thread.sleep(1) workaround and the memory still grows without bounds until 
the app crashes.  I get through about 2 runs before it crashes from memory.  
Not sure if that problem was supposed to be fixed or not.

Original comment by steve.ha...@codenameone.com on 3 Feb 2015 at 5:05

GoogleCodeExporter commented 9 years ago 
Does it run differently with the sleep?
I did add an improvement for that so it should theoretically run even without 
the sleep but we might need something more aggressive. Its also possible there 
is another memory leak.

Original comment by shai.almog on 3 Feb 2015 at 6:09

GoogleCodeExporter commented 9 years ago 
I have been testing the latest build of my full app. It is still crashing and 
using the number of rows processed before the crash, the latest build is worse 
than yesterday. Yesterday I hit 1,668 rows. Today in several tests the best I 
could do was 1,125 with the sleep and 1,118 without the sleep. Sleep doesn't 
seem to be having much effect today.

There is one interesting thing. There are two ways to get data to my app, over 
the network or transferring a file. Both were failing. We have focused on the 
file approach as it is easier to set up in this situation. Yesterday and today 
I have been able to transfer the full dataset using the network transfer. It 
can still crash but I have succeeded in getting the entire data transferred 
which I have never been able to do with the file. The routines are very 
similar, the only real difference is using the file approach we are reading the 
entire contents of the file in a tight loop. With the network approach we are 
reading data in chunks. There will be natural delays while we wait for the next 
chunk to arrive. That might mean that garbage collection has more time to do 
its work.

Original comment by mwarn...@readerware.com on 3 Feb 2015 at 7:00

GoogleCodeExporter commented 9 years ago 
I want to try an isolate whether this is triggered by a lack of GC calls or by 
an actual memory leak. Instead of using Thread.sleep can you add a call to 
System.gc() every 100 entries and see if this works around the issue?

Original comment by shai.almog on 3 Feb 2015 at 7:27

GoogleCodeExporter commented 9 years ago 
With System.gc() the load completed every time.

Original comment by mwarn...@readerware.com on 3 Feb 2015 at 8:03

GoogleCodeExporter commented 9 years ago 
I made a fix for a test case developed by Steve which I believe should remove 
the need for the System.gc(). I'd also like to know how the performance is 
compared to the old VM with recent changes.

Original comment by shai.almog on 4 Feb 2015 at 8:55

GoogleCodeExporter commented 9 years ago 
My app is freezing shortly after start up, I can't get to the point where I can 
run the test.

I have an existing database so I open it and display a list. Then I would 
normally tell it to get new data, but the database load is not completing for 
some reason. As I move around the app freezes.

I will use iTunes to delete the existing database from the device and see how 
far I can get.

Original comment by mwarn...@readerware.com on 4 Feb 2015 at 11:33

GoogleCodeExporter commented 9 years ago 
Ugh, I'll try to reproduce it with your test case.

Original comment by shai.almog on 4 Feb 2015 at 11:34

GoogleCodeExporter commented 9 years ago 
OK, it should be working now. Not sure why the other test case didn't fail on 
this too because its pretty bad...
I'm now in the 6th iteration of the unmodified test case  and so far memory 
seems to be large but stable.

Original comment by shai.almog on 4 Feb 2015 at 11:57

GoogleCodeExporter commented 9 years ago 
I deleted the existing database with iTunes then tried the load. It never got 
past 200 rows. The progress wheel continued to spin for a couple of minutes but 
the app was still at 200 rows. Then the progress wheel stopped and the app was 
frozen.

Original comment by mwarn...@readerware.com on 4 Feb 2015 at 12:18

GoogleCodeExporter commented 9 years ago 
Did you try it over with a fresh build that includes the fix I made 20 minutes 
ago?

Original comment by shai.almog on 4 Feb 2015 at 12:25

GoogleCodeExporter commented 9 years ago 
I have rebuilt my full app, no garbage collection, no sleep.

The first time I load the data, it works and I can open the database, search 
and scroll etc.

If I try and load the data a second time, the app crashes early on between 
200-300 rows.

This is repeatable, after the crash I restart, the load works fine. Loan a 
second time and it crashes.

I tried adding the gc call back but it didn't seem to help, if anything the app 
was less stable.

I can now consistently load the data the first time.

Original comment by mwarn...@readerware.com on 4 Feb 2015 at 1:35

GoogleCodeExporter commented 9 years ago 
OK, I think this is a different issue altogether.
When running the test case it did seem that memory was growing despite the GC 
activity which was odd. I'm guessing you just hit that limit and its probably 
triggered by a deeper memory leak. These are bit tricky to find since Apples 
tools are somewhat broken for memory leak detection, it would require some 
investigation.

Original comment by shai.almog on 4 Feb 2015 at 1:58

GoogleCodeExporter commented 9 years ago 
Made another fix here, related to issues 1328 that should really improve this. 
Big memory leak in the GC. Please test this and let us know if it indeed solves 
this.

Original comment by shai.almog on 5 Feb 2015 at 12:28

GoogleCodeExporter commented 9 years ago 
Didn't seem to make any difference here unfortunately. I can still run the load 
and it works fine the first time. But trying to run it again crashes the app 
100-300 rows in.

I built with the old VM and was able to run the load 5 times in a row with no 
problems. I am sure I could have gone on but 5 was enough.

Timings. On the new VM it took 1 minute 44 seconds to load a database of 1,739 
rows. On the old VM it took 1 minute 24 seconds for the same database. I timed 
each run on the old VM and the timings were consistent. So the old VM is a 
little faster.

Original comment by mwarn...@readerware.com on 5 Feb 2015 at 8:31

GoogleCodeExporter commented 9 years ago 
Can you isolate a test case that is more representative? The current test case 
doesn't crash for me anymore. I would suggest isolating that and filing a new 
issue because the number of comments here make this one harder to follow.

Original comment by shai.almog on 5 Feb 2015 at 8:36

GoogleCodeExporter commented 9 years ago 
Ran the test case again.  Now, memory grows to about 190 megs and holds steady. 
 Similar to the new behaviour in issue 1328, we now have stability.  But I 
think there is probably a lot of stuff that is getting missed by the GC before 
it starts to do its job.  190 megs seems pretty high.

Original comment by st...@weblite.ca on 6 Feb 2015 at 5:35

GoogleCodeExporter commented 9 years ago 
You have a debug environment that can still run the old VM right?
How much ram does this test case take on the old VM?
I know there is some waste in terms of RAM in the new VM (tradeoff for speed) 
but I'd like to get a sense of scale.

Original comment by shai.almog on 6 Feb 2015 at 6:43

GoogleCodeExporter commented 9 years ago 
You have a debug environment that can still run the old VM right?
How much ram does this test case take on the old VM?
I know there is some waste in terms of RAM in the new VM (tradeoff for speed) 
but I'd like to get a sense of scale.

Original comment by shai.almog on 6 Feb 2015 at 6:45

GoogleCodeExporter commented 9 years ago 
Here's where I am at with this.

My real app which is a currently shipping product will not run with the new VM, 
it is constantly crashing. I can do the load once and it will work, if I run it 
again the app will crash. My old test app has served it's purpose and now 
basically works. So as Shah suggested I am working on a new app to reproduce 
the problem. This is proving to be a lot more difficult than anticipated. My 
real app reads a line from the file, parses it with your CSVParser and adds it 
to a database. The text app just did the first two steps so I figured all I had 
to do with the test app was add the database. Unfortunately it works, I can run 
it again and again, create database after database and it works every time.

My real app is a lot more than just the database load of course and I am now 
trying to flesh out the test app with more of a UI to try and reproduce the 
problem. At the same time I find things in the real app that I think might work 
better another way and see if I can get the real app to work. It is very time 
consuming and so far I have gotten nowhere, the test app still works, my real 
app still crashes.

I think garbage collection is not freeing unused objects, it still thinks they 
are in use. The real app has class variables where the test app has local 
variables, the real app has multiple forms with links between them. The real 
app works fine on the old VM and on Android, but I think the new GC is just not 
collecting all my objects.

I am still trying to create a test app but I have other things to do too.

Original comment by mwarn...@readerware.com on 6 Feb 2015 at 8:02

GoogleCodeExporter commented 9 years ago 
@Shai:  On the old VM it starts at 13 megs.  During processing, it spikes as 
high as 25 megs.  After processing completes, it returns to 18 megs.  This 
stays pretty much constant no matter how many runs I do.

Original comment by st...@weblite.ca on 6 Feb 2015 at 8:19