IRC Logs

Log of #ghostscript at irc.freenode.net.

Search:
 <<<Back 1 day (to 2013/01/25)2013/01/26 
sebras something tells me that this has to do with reference counting...00:00.00 
  Robin_Watts: buffer_fid.00:00.12 
Robin_Watts buffer_fid = the field ID of the fileBuffer member within the class.00:00.37 
sebras you state in MuPDFCore that you can NOT do fileBuffer = buffer; because the member will just be NULL in the JNI-function.00:00.49 
Robin_Watts Once we have the field id, we can then use that to access the real value of the member.00:02.21 
sebras Robin_Watts: I added another member-variable named fileBuffer2. and in the MuPDFCore constructor I do fileBuffer2 = buffer;00:02.27 
Robin_Watts either we can set it (with SetObjectField), or we can get it, with GetObjectField.00:02.45 
sebras then at each place you access buffer_fid, I access buffer_fid2 (which points to fileBuffer2).00:02.47 
  Robin_Watts: I know.00:02.57 
Robin_Watts ok.00:03.00 
  So, what exactly are you seeing go to NULL?00:03.08 
  buffer ? or buffer_fid ?00:03.21 
  or the value of fileBuffer ?00:03.34 
sebras the reference in fileBuffer.00:03.49 
  so the latter.00:03.54 
  however I think I can correlate this going to NULL with the inner fz_try() in Java_com_artifex_mupdf_MuPDFCore_openBuffer() going out of scope.00:04.36 
  btw, JNI_FN() is not defined in all android NDKs...00:04.57 
Robin_Watts JNI_FN is not an android thing.00:05.14 
  JNI_FN is a robin thing :)00:05.20 
  see line 19.00:05.34 
sebras oh. I got a compilation error anyway.00:05.35 
  #define LOG_TAG "libmupdf" // is line 19...00:05.48 
Robin_Watts 2 lines before that ?00:06.08 
sebras nope:00:06.27 
  #include "fitz.h" 00:06.30 
  #include "fitz-internal.h" 00:06.33 
  #include "mupdf.h" 00:06.36 
  #define LOG_TAG "libmupdf" 00:06.39 
  #define LOGI(...) __android_log_print(ANDROID_LOG_INFO,LOG_TAG,__VA_ARGS__) 00:06.42 
  #define LOGT(...) __android_log_print(ANDROID_LOG_INFO,"alert",__VA_ARGS__) 00:06.45 
  #define LOGE(...) __android_log_print(ANDROID_LOG_ERROR,LOG_TAG,__VA_ARGS__) 00:06.48 
Robin_Watts #include "mupdf.h"00:06.54 
  #define JNI_FN(A) Java_com_artifex_mupdfdemo_ ## A00:06.56 
  #define PACKAGENAME "com/artifex/mupdfdemo"00:06.58 
  #define LOG_TAG "libmupdf"00:07.00 
  You may have a screwed up version of the source.00:07.33 
sebras oh...00:07.45 
  I just cherry-picked the nulpinter and content:// commits... and JNI_FN appears somewhere else.00:08.17 
  ok, anyway. :)00:08.30 
Robin_Watts ah, ok.00:08.45 
sebras as I said the value of fileBuffer suddenly becomes NULL.00:08.46 
  this is the reason for the SIGSEGV.00:08.53 
Robin_Watts are you watching this in adb logcat ?00:09.17 
  does that mention gc runs?00:09.25 
sebras because in bufferStreamSeek() you use array when computing arrayLength without verifying that array != NULL...00:09.43 
  by checking this I can avoid the crash, but it still fails to parse the file (no data to parse!)...00:10.02 
Robin_Watts Right, because we should never get into here without array being non NULL.00:10.09 
sebras yes, adb logcat. let me check for GC...00:10.17 
Robin_Watts How the hell is it losing the reference.00:10.24 
sebras D/dalvikvm(17226): GC_EXTERNAL_ALLOC freed 9K, 10% free 24230K/26887K, external 0K/0K, paused 28ms00:11.00 
  that's the only line.00:11.04 
Robin_Watts ok, so there is a gc running.00:11.16 
  let's try a hack in the java.00:11.22 
sebras however _after_ this line is executed then the pointer is == NULL.00:11.25 
Robin_Watts in MuPDFCore.java...00:11.31 
  before public MuPDFCore(byte buffer[]) throws Exception00:11.48 
  add00:11.51 
  public void stupidJavaHack(byte buffer[]) { fileBuffer = buffer; }00:12.29 
  Then before: globals = openBuffer(buffer); do: stupidJavaHack(buffer);00:12.54 
sebras compiles00:13.57 
sebras compiles slowly...00:14.09 
sebras tests...00:14.16 
  fileBuffer remains valid after the GC in this case.00:15.00 
  eventually it crashes due to "ReferenceTable overflow (max=512)"00:15.30 
Robin_Watts OK. In mupdf.c comment out the SetObjectValue line.00:16.00 
sebras SetObjectField..?00:16.28 
Robin_Watts SetObjectField, sorry.00:16.28 
sebras do you want me to replace this with something?00:16.41 
  w8...00:16.59 
Robin_Watts no, just comment it out and recompile.00:17.26 
  The stupidJavaHack does what it was doing.00:17.36 
sebras some of my own debug-stuff might still have been present. I'm retesting.00:18.10 
  Robin_Watts: crashes anyway. now I'm testing without SetObjectField...00:19.03 
  Robin_Watts: without SetObjectField it fails on the first bufferStreamRead()....00:20.51 
Robin_Watts Gah.00:21.11 
  so it does look like reference counting is being screwed up.00:21.37 
sebras yup.00:21.47 
Robin_Watts It's as if when I assign from C it doesn't realise that a reference has been taken.00:21.54 
sebras exactly.00:22.02 
  did you get what I was trying to explain about fileBuffer2 before?00:22.20 
Robin_Watts That if you made a second copy, it lasted longer?00:24.39 
  I suspect we should go back to my original code and call NewGlobalRef.00:25.50 
sebras no, it didn't last _longer_, fileBuffer2 was NULL whenever I accessed it via GetObjectField() up until the time when your pointer became NULL!00:27.23 
Robin_Watts oh, and it became non NULL.00:27.48 
sebras after this time, then fileBuffer2 returned non-NULL from GetObjectField() while fileBuffer returned NULL...00:27.50 
Robin_Watts There is something hellawierd going on.00:28.00 
sebras exactly. the non-NULL values were not the same though...00:28.02 
  there is definitely something concerning reference counting which is not obivous. :)00:28.19 
  Robin_Watts: I have a question...00:33.53 
Robin_Watts I *suspect*, but I cannot find information to be sure, that the params that come in to JNI functions are local references.00:34.02 
  and once the gc runs, any local references may disappear if they aren't being used again later in the function.00:34.22 
sebras while we're in android/jni/mupdf.c::openBuffer(), how cane the GC be running? or rather what triggers the GC in this situation?00:34.34 
Robin_Watts so possibly we should take a new global reference before assigning it.00:34.34 
sebras how does the GC _know_ whether the objects have gone out of scope or not?00:34.48 
Robin_Watts GC can run during JNI calls, the docs are clear on that.00:34.52 
sebras they are local refs: http://developer.android.com/training/articles/perf-jni.html#local_and_global_references00:35.13 
  I attempted to call NewGlobalRef() but couldn't get it to work. I might have messed it up.00:36.19 
Robin_Watts The alerts_init() call calls some pthreads_stuff.00:36.23 
  how goes the gc know? hell if I know.00:36.44 
sebras ah.. so it does.00:36.47 
  I guess the GC knows depending on whether one has called NewGlocalRef() or not and where in the java code one is currently executing.00:37.14 
  did you read the link?00:37.21 
Robin_Watts I am reading it.00:37.36 
sebras good.00:37.47 
  I can forsee that we might want to care about the threading eventually, but right now this should not be a problem right? because there's only a single thread being active AFAIK.00:38.43 
Robin_Watts nooo. several threads.00:39.14 
  The UI is all on one thread. rendering all on another.00:39.33 
  and alert stuff on another.00:39.49 
  (the alerts have to call back into the java - it's a nightmare)00:40.06 
sebras and the alerts were added for forms, no..?00:40.26 
Robin_Watts yes.00:40.30 
  I think I need to take a GlobalReference.00:40.44 
sebras agreed.00:40.49 
Robin_Watts The question is, do I then need to free it on closedown?00:40.54 
sebras I think so.00:41.02 
  so basically in bufferStreamClose I guess...00:41.11 
Robin_Watts I don't currently have a destructor. I'll have to add one.00:41.21 
sebras do JNI-objects have destructors?00:41.45 
Robin_Watts No. I'd add a ~MuPDFCore (a java destructor).00:42.07 
  and have that call a native 'die' method that could remove the reference and set it to NULL.00:42.28 
  That way the only access to that member is from the JNI.00:42.59 
  Hopefully that should minimise the risk of things getting confused.00:43.11 
  What a pain.00:43.24 
sebras pardon my ignorance, but does Java objects have destructors?00:43.41 
  I left java around 1.4, so it might have been added, but up until then I never saw one...00:44.06 
Robin_Watts Oh God, am I horribly confused?00:44.26 
  Yeah, I'm thinking of C++ :(00:45.05 
sebras Robin_Watts: though there is an inherited finalize() method.00:45.32 
  apparently this is where classes are supposed to do the tidying.00:45.47 
Robin_Watts Which is inherited at the discretion of the garbage collector00:45.48 
  s/inherited/implemented/00:45.58 
sebras called really.00:46.07 
Robin_Watts I'll have a look tomorrow and see if I can come up with something.00:46.23 
  Thank you for your help on this - it is much appreciated!00:46.37 
  (as always)00:46.41 
sebras sure. MuPDF is my baby too! :)00:46.58 
  though not formally, but enough for me to be annoyed when it is misbehaving.00:47.18 
  btw, I managed to run ndk-stack which was really useful.00:47.58 
  didn't get ndk-gdb working though...00:48.05 
Robin_Watts I've never managed to get anything useful out of either of them.00:48.34 
  I must go to bed. Helen is unwell.00:49.09 
  Talk to you tomorrow.00:49.16 
sebras Robin_Watts: I cut and pasted the SIGSEGV part of logcat to a file and ran ndk-stack -sym obj/local/armeabi -dump crash.txt which pointed to the array variable in bufferStreamSeek being the culprit.00:49.56 
  oh, of course. see you!00:50.09 
Robin_Watts sebras: ping ?12:09.59 
sebras Robin_Watts: pong!12:50.22 
Robin_Watts hi.12:50.37 
  I tried another idea to fix this thing, and it's still failing.12:50.51 
  I cannot understand why when I set the fileBuffer member from the java, I cannot then read it in the C.12:51.10 
sebras no, exactly. that's what your comment is all about.12:51.28 
Robin_Watts I've split the code so that the MuPDFCore constructor sets the member and then exits.12:51.29 
sebras ok.12:51.39 
Robin_Watts and then I have another method that calls the native one.12:51.40 
  The method that calls the native one prints the fileBuffer, and I get a valid value out.12:52.04 
  So it *is* being set. the JNI is just failing to get it.12:52.18 
sebras telephones...12:52.19 
  right.12:55.15 
  do we have to call some function in order to "set" all the references properly?12:55.51 
Robin_Watts I don't see how.12:56.20 
sebras I don't think it matters if it is a global reference, right?12:56.29 
Robin_Watts The java side sets the 'globals' member, and the C retrieves that just fine.12:56.40 
  so I'm not trying to do anything fundamentally different to what I've done before.12:57.06 
sebras so basically you do GetObjectClass(), GetFieldID() and then GetByteArrayField() or whatever it is called..?13:01.57 
  except that GetObjectClass and GetFieldID() are done in openBuffer...13:03.59 
  and GetObjectField() is called in bufferStreamSeek() etc.13:04.14 
Robin_Watts yes.13:08.19 
  OK, I just tried a test.13:08.23 
sebras http://stackoverflow.com/questions/1086596/how-to-access-arrays-within-an-object-with-jni13:08.24 
  I can't see what we are doing wrong...13:08.32 
Robin_Watts yeah, I've read that one :)13:09.12 
  My test is as follows:13:09.17 
  Have a constructor: MuPDFCore(byte buffer[]) { fileBuffer =buffer; globals = 64; }13:09.48 
  Then I have a java method: void openBufferedFile() { System.out.println("globals="+globals+" fileBuffer="+fileBuffer); globals = openBuffer(); }13:10.42 
  Then in the native method openBuffer, I retrieve globals and fileBuffer and print both of them.13:11.05 
  The calling code obviously calls: core = new MuPDFCore(buffer); then core.openBufferedFile();13:11.47 
  I see the java print give globals=64 fileBuffer=[B@4055b51013:12.11 
  so that's what we expect.13:12.16 
  Inside the native method however, I see 0 for both values.13:12.26 
  I have to pop out for a bit. There must be something stupidly simple I'm doing wrong here.13:18.42 
  I see it, I think.13:21.03 
  I'm reading the values from 'clazz' not 'thiz'.13:21.32 
  OK. I think I know how to fix it. I'll tidy that all up when I get back.13:22.37 
sebras is back.14:31.30 
  Robin_Watts: oh, yes, of course. those are instance members, not class members! :)14:32.39 
  d'oh.14:32.42 
Robin_Watts is back too.15:53.04 
  rebuilding now to test.15:53.07 
sebras Robin_Watts: ok. have you managed to reproduce?16:05.42 
  or do you still want me to test it?16:05.58 
Robin_Watts I had code here to simulate it, and it seems to test out OK.16:07.14 
  but I'd still like it tested for real if you wouldn't mind.16:07.24 
  I should have an apk in about 10 mins.16:07.32 
  (takes 5 mins to upload to the website)16:07.50 
  sebras: http://ghostscript.com/~robin/MuPDF.apk16:18.03 
sebras nope.16:19.37 
Robin_Watts oh ass.16:20.12 
sebras let me uninstall all my mupdf apps just to be sure that I used the right one...16:20.15 
Robin_Watts really? What error?16:20.18 
sebras E/AndroidRuntime(11826): java.lang.UnsatisfiedLinkError: openBuffer16:21.54 
  E/AndroidRuntime(11826): at com.artifex.mupdf.MuPDFCore.openBuffer(Native Method)16:21.55 
  I removed all apps on my phone and reinstalled the one you sent me. probably I accidentally used my old one before, because now I get a different error...16:23.36 
  Robin_Watts: http://pastebin.com/Ba8uVjn916:24.48 
Robin_Watts I've been caught out by the fact that if you download MuPDF.apk, and there is already a MuPDF.apk there, it renames the new one to be MuPDF-1.apk, and I've ended up reinstalling the same one several times.16:24.54 
  How big is that attachment ?16:25.45 
sebras 21Mbyte...16:25.49 
Robin_Watts Try a smaller one ?16:25.55 
sebras I can try the smaller one too.16:25.58 
Robin_Watts I think (hope) this may be a crash due to running out of memory.16:26.19 
sebras nope, same crash.16:26.39 
  NullPointerException in doInBackground line 152...16:26.54 
Robin_Watts ok, that's crashing in the alert stuff.16:27.24 
sebras my line 152 has a brace, so I'm obviously now having the latest MuPDFActivity.java...16:27.30 
Robin_Watts gimme a mo, and I'll push it.16:27.48 
sebras sure.16:27.57 
Robin_Watts ok, pushed16:29.04 
  Do you see "Trying to open byte buffer" in the logs ?16:30.36 
sebras nope.16:31.53 
  I'll build it myself too.16:32.00 
  same result.16:32.56 
  Robin_Watts: how can the core member on line 152 be NULL?16:33.45 
Robin_Watts Oh, I was reading it as being a NULL exception from within core.waitForAlert.16:34.57 
  but I think you're right - that would have been a SEGV, right?16:35.12 
  So... I don't know.16:35.20 
  Look at around line 32616:36.07 
  if (str == null) then we aren't being given a filename.16:36.21 
  so we have to try to work in a buffered manner.16:36.31 
  I'm wondering if we're somehow ending up in the if (failString != null) section, and that trys to set up an alert, and the alert is failing because we don't have a core object.16:37.27 
  Not being able to use alerts without a core object is a bit of an ass.16:38.17 
  and something I need to sort out I guess in order to be able to neatly report errors.16:38.38 
  BUT... we shouldn't be ending up there anyway.16:38.47 
  at least, not with the smaller attachment.16:38.54 
  So I'm guessing that a sprinkling of debugging printfs in the try/catch stuff may point to where we're going wrong?16:39.23 
sebras I was unsure whether those printlns would actually make it into logcat, so I replaced them with Log.e()...16:39.55 
  but I don't see them from openBuffer/openFile anyway..16:40.07 
  something ells me that we haven't visited those functions yet...16:40.16 
Robin_Watts right. If we're going wrong in the try/catch thing, then we don't get that far.16:40.35 
  I reckon we are throwing an exception in the 328->332 region.16:41.03 
sebras of what file? MuPDFActivity?16:41.15 
Robin_Watts Yes.16:41.19 
  And that's being caught, and we're crashing in 344->35716:41.42 
sebras I added a print on line 321, and I don't see that one either...16:41.54 
  let me add one at the very start of onCreate()...16:42.31 
  nope... that's not printed either.16:42.57 
  E/AndroidRuntime(16459): Caused by: java.lang.NullPointerException16:43.01 
  E/AndroidRuntime(16459): at com.artifex.mupdfdemo.MuPDFActivity$1.doInBackground(MuPDFActivity.java:152)16:43.02 
  could it be that doInBackground() is called before core is set?16:43.26 
  even if I have a print at the beginnig of createAlertWaiter() I don't see it.16:45.49 
  Robin_Watts: I give up. :-P I fail to see how it can end up in a NullPointException at line 152 without passing the lines before it and printing something!16:48.03 
Robin_Watts I can't see how we're ever getting into that particular alert stuff :(16:48.54 
sebras I'll replace that core.waitForAlert() line with return null just to see if I get more debugprints or something...16:50.24 
  nothing.16:52.37 
Robin_Watts sebras: On the phone to paulgardiner16:52.52 
sebras actually it is worse now than yesterday evening.16:52.55 
Robin_Watts ok.17:01.53 
  I think I understand what's going wrong.17:01.59 
  Or at least, I might do.17:02.07 
sebras do tell! :)17:02.20 
Robin_Watts When onStart is called, we start up the horrible alertwaiter stuff in the background.17:02.35 
  That assumes that we have a core.17:03.06 
  Normally, we go into onCreate, and don't come out without having a core.17:03.21 
sebras right. but I put a print _before_ the call to core.startAlerts() and I don't see that print either.17:03.27 
Robin_Watts so onStart is fine.17:03.37 
sebras could be because the printbuffer is not flushed of course, but still.17:03.38 
Robin_Watts just don't ruin a nice idea, eh?17:03.44 
sebras Robin_Watts: >;)17:03.57 
Robin_Watts If we put an error dialogue on the screen, we can now exit onCreate without having created a core.17:04.22 
sebras in what order are onCreate and onStart called?17:04.36 
Robin_Watts hence we then run onStart and that creates the alert waiter and it all falls over.17:04.47 
  onCreate -> {onStart->onStop)* -> onDestroy, I think.17:05.07 
sebras seems reasonable.17:05.19 
Robin_Watts So onStart should be changed so that both core.startAlerts and createAlertWaiter are in the if (core != null)/17:05.43 
sebras I have a Log.e("mupdf", "AAAAAA"); at the beginning of onCreate and onStart... I don't ser either in logcat.17:06.00 
Robin_Watts and onStop should be changed so that both destroyAlertWaiter and core.stopAlerts() are in the if (core != null)17:06.11 
  Let's hope that's just thready flushy problems.17:06.28 
  Try changing onStart/onStop and see if anything works.17:06.43 
sebras tests17:08.28 
  Robin_Watts: well, it doesn't crash then..17:12.44 
  I can now see that it visits both onCreate and onStart in the log.17:12.59 
  however I get an alertbox on screen which has nothing in it apart from a big dismiss-button.17:13.23 
Robin_Watts ok, that's good news.17:13.36 
sebras if I press it MuPDF closes...17:13.49 
Robin_Watts Line 34917:13.58 
  setTitle(String.format(...))17:14.06 
  That should be alert.setTitle(17:14.18 
  Then you should actually see the exception that was thrown.17:14.29 
sebras Robin_Watts: and here's the magical string v v v v v17:15.52 
  Unable to open document:17:15.59 
  doesn't this mean that failString is empty?17:16.31 
Robin_Watts Oh, FFS. I am such a plonker.17:16.34 
  Line 325.17:16.47 
  String failString = ""; should be String failString = null;17:17.01 
sebras well, that explains why we get an alert box. :)17:17.38 
  I see a PDF!17:18.47 
  now let me try this with the 21Mbyte file...17:18.56 
Robin_Watts For the smaller attachment? cool.17:19.00 
sebras E/mupdf (21582): Trying to open byte buffer17:19.33 
  E/libmupdf(21582): Opening document...17:19.33 
  E/libmupdf(21582): error: Failed to read linearized dictionary17:19.33 
  I/alert (21582): alert_init17:19.33 
  E/libmupdf(21582): Done!17:19.33 
  W/dalvikvm(21582): ReferenceTable overflow (max=512)17:19.36 
  W/dalvikvm(21582): Last 10 entries in JNI local reference table:17:19.38 
  W/dalvikvm(21582): 502: 0x40541788 cls=[B (22007140 bytes)17:20.06 
  W/dalvikvm(21582): 503: 0x40541788 cls=[B (22007140 bytes)17:20.06 
  W/dalvikvm(21582): 504: 0x40541788 cls=[B (22007140 bytes)17:20.06 
  W/dalvikvm(21582): 505: 0x40541788 cls=[B (22007140 bytes)17:20.06 
  this looks like we're leeking a bytearray-reference somewhere now...?17:20.20 
Robin_Watts hmm. That might be in the bufferStream stuff.17:20.55 
sebras mmm.17:21.00 
Robin_Watts When I do a GetObjectStream, that should get me a local reference.17:21.11 
  I'm not supposed to need to throw that away.17:21.18 
sebras GetObjectField you mean..?17:21.31 
Robin_Watts yes, sorry.17:21.37 
sebras well, at the end of bufferStream(Read|Seek) we might be rqeuired to..?17:22.02 
Robin_Watts http://mono-for-android.1047100.n5.nabble.com/JNI-ERROR-app-bug-local-reference-table-overflow-max-512-td5711318.html17:22.38 
sebras there is a DeleteLocalRef function.17:22.39 
Robin_Watts seems that's what I need, yes. Will fix now.17:22.50 
  OK, I've pushed what I think should be the fixed version.17:27.52 
  I've got to go tend to Helen for a bit though, sorry.17:28.02 
  Thanks for all your help on this!17:28.08 
sebras np.17:28.10 
  Robin_Watts: congrats I have a pdf!17:38.52 
Robin_Watts brilliant.17:45.19 
  Uploading release build to the usual place. ETA 5 mins.17:50.00 
sebras well... that one wasn't so fun.18:17.33 
  ah... no I see what is happening.18:17.47 
  nvm me.18:17.49 
  Robin_Watts: if I have a prior version of the app installed and I do adb install of your MuPDF.apk I get some of the files from the old version and some from the new...18:20.54 
  now it works elegantly.18:21.06 
  even with the large file.18:21.17 
Robin_Watts sebras: Thanks.19:21.59 
 Forward 1 day (to 2013/01/27)>>> 
ghostscript.com
Search: