September 2011 - Dillo-dev - lists.mailman3.com

valgrind still unhappy despite expect changes

by jcid＠dillo.org

On Thu, Sep 01, 2011 at 10:56:19AM -0300, Jorge Arellano Cid wrote: > On Thu, Sep 01, 2011 at 03:38:58PM +0200, Johannes Hofmann wrote: > > On Thu, Sep 01, 2011 at 09:57:39AM -0300, Jorge Arellano Cid wrote: > > > On Wed, Aug 31, 2011 at 09:42:21PM +0000, corvid wrote: > > > > Jorge wrote: > > > > [...] > > > > In this one > > > > http://starurchin.org/dillo/valgrind/7ea9fc809376ddf7dde2908e2ecf999aea2741… > > > > at least, it looks pretty clear that the bw is gone. > > > [...] > > > Does the invalid read apply to 'bw' or 'bw->nav_expect_url'? > > > (I don't know valgrind's semantics on it) > > > > I'd guess bw is no longer pointing to valid memory (i.e. has been > > free'd) and therefore reading the 4 byte nav_expect_url pointer > > causes the valgrind message. > > OK, this line gave light in that direction: > > ==28991== Address 0x6961a34 is 44 bytes inside a block of size 68 free'd > > ... and I observe that bw has 17 items, 17*4 = 68, > and the expect URL is the 12th item, (12-1)*4 = 44. > > So it's an already freed 'bw' and not its expected URL. > > This starts to make sense... ;-) BTW, why there are two different stack traces? What does the second one mean with respect to the first? If I look the first one (in reading order), it's clear that a keyboard event closed a browser window cancelling the expect. This is, for instance, middle-click a link, hit Ctrl-W before the data stream starts to arrive (while dillo displays the "contacting host" message). In my machine this happens in the expected order with no problems. Can anybody reproduce the valgrind log using this procedure? OTOH, analyzing the code: AFAIS: * The only place where a bw is freed is in a_UIcmd_close_bw [3]: (the only call to a_Bw_free() in the codebase). * bw is valid at [1] * The problematic a_Nav_cancel_expect_if_eq() is called from inside the call chain at [2]. * No other a_UIcmd_close_bw() appears in the log, so how came bw to be invalid then? void a_UIcmd_close_bw(void *vbw) { BrowserWindow *bw = (BrowserWindow *)vbw; UI *ui = BW2UI(bw); CustTabs *tabs = ui->tabs(); 1 Layout *layout = (Layout*)bw->render_layout; MSG("a_UIcmd_close_bw bw=%p\n", bw); 2 a_Bw_stop_clients(bw, BW_Root + BW_Img + BW_Force); delete(layout); if (tabs) { tabs->remove_tab(ui); if (tabs->num_tabs() == 0) delete tabs->window(); } 3 a_Bw_free(bw); MSG("a_UIcmd_close_bw freed(bw=%p)\n", bw); } Any help is appreciatted. -- Cheers Jorge.-

Sept. 1, 2011

valgrind still unhappy despite expect changes

by jcid＠dillo.org

On Thu, Sep 01, 2011 at 03:38:58PM +0200, Johannes Hofmann wrote: > On Thu, Sep 01, 2011 at 09:57:39AM -0300, Jorge Arellano Cid wrote: > > On Wed, Aug 31, 2011 at 09:42:21PM +0000, corvid wrote: > > > Jorge wrote: > > > > On Tue, Aug 30, 2011 at 06:19:38PM +0100, Jeremy Henty wrote: > > > > > > > > > > Jorge Arellano Cid wrote: > > > > > > > > > > > On Tue, Aug 30, 2011 at 12:34:59AM +0100, Jeremy Henty wrote: > > > > > > > > > > > > > > I compile Dillo with 'configure "CFLAGS=-g -O0" "CXXFLAGS= -g > > > > > > > -O0"' to minimise false positives from gcc optimization. > > > > > > > > > > > > Ack. > > > > > > > > > > > > Given you got the log. Do you have a way to reproduce it, or at > > > > > > least have a memory of what you were doing? > > > > > > > > > > Unfortunately no. I automatically run dillo inside valgrind and log > > > > > the output. A cron job reads the logs and updates the reports. These > > > > > days I rarely even look at the logs unless something in the mailing > > > > > list prompts me to. > > > > > > > > > > I am wondering how to add debugging information that could help tie > > > > > valgrind reports to Dillo's actions. Perhaps the CCC could log which > > > > > of its chains is active and which URL it was serving? Then if dlib > > > > > logged its allocations and frees maybe we could identify the URL that > > > > > was responsible? > > > > > > > > Even having the URL wouldn't help much in this case because we > > > > need to know which "cancel" action triggered the last call to > > > > a_Nav_cancel_expect_if_eq(). This would require logging user > > > > actions. > > > > > > > > OTOH, trying to re-build a user action pattern from the CCC > > > > logs would be almost impossible for a human brain (if possible at > > > > all). ;) > > > > > > > > More technically: > > > > > > > > Each bw has its own nav_expect_url; a private copy of a > > > > DilloUrl. Valgrind complains about nav_expect_url, not the bw. So > > > > I wonder how can the bw be valid and not the nav_expect_url, > > > > which is either NULL or a private copy of a DilloUrl? > > > > > > In this one > > > http://starurchin.org/dillo/valgrind/7ea9fc809376ddf7dde2908e2ecf999aea2741… > > > at least, it looks pretty clear that the bw is gone. > > > > Oh, it may be my mistake then. > > > > ==28991== Invalid read of size 4 > > ==28991== at 0x805760A: a_Bw_expected_url (bw.c:336) > > > > bw.c:336 > > return bw->nav_expect_url; > > > > Does the invalid read apply to 'bw' or 'bw->nav_expect_url'? > > (I don't know valgrind's semantics on it) > > I'd guess bw is no longer pointing to valid memory (i.e. has been > free'd) and therefore reading the 4 byte nav_expect_url pointer > causes the valgrind message. OK, this line gave light in that direction: ==28991== Address 0x6961a34 is 44 bytes inside a block of size 68 free'd ... and I observe that bw has 17 items, 17*4 = 68, and the expect URL is the 12th item, (12-1)*4 = 44. So it's an already freed 'bw' and not its expected URL. This starts to make sense... ;-) -- Cheers Jorge.-

Sept. 1, 2011

valgrind still unhappy despite expect changes

by johannes.hofmann＠gmx.de

On Thu, Sep 01, 2011 at 09:57:39AM -0300, Jorge Arellano Cid wrote: > On Wed, Aug 31, 2011 at 09:42:21PM +0000, corvid wrote: > > Jorge wrote: > > > On Tue, Aug 30, 2011 at 06:19:38PM +0100, Jeremy Henty wrote: > > > > > > > > Jorge Arellano Cid wrote: > > > > > > > > > On Tue, Aug 30, 2011 at 12:34:59AM +0100, Jeremy Henty wrote: > > > > > > > > > > > > I compile Dillo with 'configure "CFLAGS=-g -O0" "CXXFLAGS= -g > > > > > > -O0"' to minimise false positives from gcc optimization. > > > > > > > > > > Ack. > > > > > > > > > > Given you got the log. Do you have a way to reproduce it, or at > > > > > least have a memory of what you were doing? > > > > > > > > Unfortunately no. I automatically run dillo inside valgrind and log > > > > the output. A cron job reads the logs and updates the reports. These > > > > days I rarely even look at the logs unless something in the mailing > > > > list prompts me to. > > > > > > > > I am wondering how to add debugging information that could help tie > > > > valgrind reports to Dillo's actions. Perhaps the CCC could log which > > > > of its chains is active and which URL it was serving? Then if dlib > > > > logged its allocations and frees maybe we could identify the URL that > > > > was responsible? > > > > > > Even having the URL wouldn't help much in this case because we > > > need to know which "cancel" action triggered the last call to > > > a_Nav_cancel_expect_if_eq(). This would require logging user > > > actions. > > > > > > OTOH, trying to re-build a user action pattern from the CCC > > > logs would be almost impossible for a human brain (if possible at > > > all). ;) > > > > > > More technically: > > > > > > Each bw has its own nav_expect_url; a private copy of a > > > DilloUrl. Valgrind complains about nav_expect_url, not the bw. So > > > I wonder how can the bw be valid and not the nav_expect_url, > > > which is either NULL or a private copy of a DilloUrl? > > > > In this one > > http://starurchin.org/dillo/valgrind/7ea9fc809376ddf7dde2908e2ecf999aea2741… > > at least, it looks pretty clear that the bw is gone. > > Oh, it may be my mistake then. > > ==28991== Invalid read of size 4 > ==28991== at 0x805760A: a_Bw_expected_url (bw.c:336) > > bw.c:336 > return bw->nav_expect_url; > > Does the invalid read apply to 'bw' or 'bw->nav_expect_url'? > (I don't know valgrind's semantics on it) I'd guess bw is no longer pointing to valid memory (i.e. has been free'd) and therefore reading the 4 byte nav_expect_url pointer causes the valgrind message.

Sept. 1, 2011

valgrind still unhappy despite expect changes

by jcid＠dillo.org

On Wed, Aug 31, 2011 at 09:42:21PM +0000, corvid wrote: > Jorge wrote: > > On Tue, Aug 30, 2011 at 06:19:38PM +0100, Jeremy Henty wrote: > > > > > > Jorge Arellano Cid wrote: > > > > > > > On Tue, Aug 30, 2011 at 12:34:59AM +0100, Jeremy Henty wrote: > > > > > > > > > > I compile Dillo with 'configure "CFLAGS=-g -O0" "CXXFLAGS= -g > > > > > -O0"' to minimise false positives from gcc optimization. > > > > > > > > Ack. > > > > > > > > Given you got the log. Do you have a way to reproduce it, or at > > > > least have a memory of what you were doing? > > > > > > Unfortunately no. I automatically run dillo inside valgrind and log > > > the output. A cron job reads the logs and updates the reports. These > > > days I rarely even look at the logs unless something in the mailing > > > list prompts me to. > > > > > > I am wondering how to add debugging information that could help tie > > > valgrind reports to Dillo's actions. Perhaps the CCC could log which > > > of its chains is active and which URL it was serving? Then if dlib > > > logged its allocations and frees maybe we could identify the URL that > > > was responsible? > > > > Even having the URL wouldn't help much in this case because we > > need to know which "cancel" action triggered the last call to > > a_Nav_cancel_expect_if_eq(). This would require logging user > > actions. > > > > OTOH, trying to re-build a user action pattern from the CCC > > logs would be almost impossible for a human brain (if possible at > > all). ;) > > > > More technically: > > > > Each bw has its own nav_expect_url; a private copy of a > > DilloUrl. Valgrind complains about nav_expect_url, not the bw. So > > I wonder how can the bw be valid and not the nav_expect_url, > > which is either NULL or a private copy of a DilloUrl? > > In this one > http://starurchin.org/dillo/valgrind/7ea9fc809376ddf7dde2908e2ecf999aea2741… > at least, it looks pretty clear that the bw is gone. Oh, it may be my mistake then. ==28991== Invalid read of size 4 ==28991== at 0x805760A: a_Bw_expected_url (bw.c:336) bw.c:336 return bw->nav_expect_url; Does the invalid read apply to 'bw' or 'bw->nav_expect_url'? (I don't know valgrind's semantics on it) -- Cheers Jorge.-

Sept. 1, 2011