* Who's insane: gdb or I?
@ 2002-07-03 6:16 Bernd Jendrissek
2002-07-03 6:24 ` Eli Zaretskii
` (3 more replies)
0 siblings, 4 replies; 6+ messages in thread
From: Bernd Jendrissek @ 2002-07-03 6:16 UTC (permalink / raw)
To: gdb
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
I'm busy trying to hunt down a problem with INN (2.3.3), and at one point
I thought I might have found a compiler bug. But nooo... (more below)
1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000;
(gdb) s
1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000;
(gdb) s
1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000;
(gdb) s
1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000;
(gdb) s
1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000;
(gdb) s
1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000;
(gdb) list
1079 return;
1080 }
1081 if (PERMaccessconf->nnrpdoverstats) {
1082 gettimeofday(&etv, NULL);
1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000;
1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000;
1085 }
1086
1087 if (av[1] != NULL)
1088 Reply("%d %s fields follow\r\n", NNTP_OVERVIEW_FOLLOWS_VAL, av[1]);
(gdb) print OVERtime
$26 = 0
######### I can understand this if OVERtime is still in a register...
(gdb) print etv
$27 = {tv_sec = 1025700128, tv_usec = 739014}
(gdb) print etv stv
A parse error in expression, near `'.
(gdb) print etv, stv
$28 = {tv_sec = 1025700032, tv_usec = 32372}
(gdb) print etv
$29 = {tv_sec = 1025700128, tv_usec = 739014}
(gdb) print stv
$30 = {tv_sec = 1025700032, tv_usec = 32372}
objdump -S nnrpd of the relevant part:
if (PERMaccessconf->nnrpdoverstats) {
804cb25: a1 e8 9b 06 08 mov 0x8069be8,%eax
804cb2a: 83 78 74 00 cmpl $0x0,0x74(%eax)
804cb2e: 74 48 je 804cb78 <CMDxover+0x15c>
gettimeofday(&etv, NULL);
804cb30: 83 c4 f8 add $0xfffffff8,%esp
804cb33: 6a 00 push $0x0
804cb35: 8d 5d d0 lea 0xffffffd0(%ebp),%ebx
804cb38: 53 push %ebx
804cb39: e8 b6 d9 ff ff call 804a4f4 <_init+0x780>
OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000;
804cb3e: 8b 45 d8 mov 0xffffffd8(%ebp),%eax
804cb41: 8b 4d d0 mov 0xffffffd0(%ebp),%ecx
804cb44: 29 c1 sub %eax,%ecx
OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000;
804cb46: 8b 45 dc mov 0xffffffdc(%ebp),%eax
804cb49: 8b 73 04 mov 0x4(%ebx),%esi
804cb4c: 69 c9 e8 03 00 00 imul $0x3e8,%ecx,%ecx
804cb52: 29 c6 sub %eax,%esi
804cb54: bb d3 4d 62 10 mov $0x10624dd3,%ebx
804cb59: 89 f0 mov %esi,%eax
804cb5b: f7 eb imul %ebx,%eax
804cb5d: 03 0d b0 9b 06 08 add 0x8069bb0,%ecx
804cb63: c1 fa 06 sar $0x6,%edx
804cb66: 89 f0 mov %esi,%eax
804cb68: c1 f8 1f sar $0x1f,%eax
804cb6b: 29 c2 sub %eax,%edx
804cb6d: 01 d1 add %edx,%ecx
804cb6f: 89 0d b0 9b 06 08 mov %ecx,0x8069bb0
}
804cb75: 83 c4 10 add $0x10,%esp
Which all seems fine.
Why did gdb tell me that the "OVERtime+=..." part happened several times
over? A bad interaction with CFLAGS="... -O2 ..."? Still, there are no
jumps in the generated assembly... And why would gdb's idea of the
"current" line-number cycle between 1083 and 1084?
Bernd Jendrissek
- --
berndj@users.sourceforge.net is probably better to bookmark than any
employer-specific email address I may have appearing in the headers.
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.0.4 (GNU/Linux)
Comment: For info see http://www.gnupg.org
iD8DBQE9Ivjt/FmLrNfLpjMRAhK2AJ9Lb7wjqA1Oj4V2CS9JWrF7n1DavwCfSt55
sgKfxWFsdH++XtlnjRS350A=
=u+rm
-----END PGP SIGNATURE-----
^ permalink raw reply [flat|nested] 6+ messages in thread* Re: Who's insane: gdb or I? 2002-07-03 6:16 Who's insane: gdb or I? Bernd Jendrissek @ 2002-07-03 6:24 ` Eli Zaretskii 2002-07-03 6:42 ` Kris Warkentin 2002-07-03 9:29 ` Carlo Wood ` (2 subsequent siblings) 3 siblings, 1 reply; 6+ messages in thread From: Eli Zaretskii @ 2002-07-03 6:24 UTC (permalink / raw) To: Bernd Jendrissek; +Cc: gdb On Wed, 3 Jul 2002, Bernd Jendrissek wrote: > Why did gdb tell me that the "OVERtime+=..." part happened several times > over? Because compiler optimizations move code around, so that the machine instructions generated for those two lines are interleaved. Simply get used to this. I usually wait until the line shjown by GDB is after the one I'm interested in, and then print the relevant variables. ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Who's insane: gdb or I? 2002-07-03 6:24 ` Eli Zaretskii @ 2002-07-03 6:42 ` Kris Warkentin 0 siblings, 0 replies; 6+ messages in thread From: Kris Warkentin @ 2002-07-03 6:42 UTC (permalink / raw) To: Eli Zaretskii, Bernd Jendrissek; +Cc: gdb > On Wed, 3 Jul 2002, Bernd Jendrissek wrote: > > > Why did gdb tell me that the "OVERtime+=..." part happened several times > > over? > > Because compiler optimizations move code around, so that the machine > instructions generated for those two lines are interleaved. > > Simply get used to this. I usually wait until the line shjown by GDB is > after the one I'm interested in, and then print the relevant variables. I get this all the time too so I usually debug code compiled without optimization. Unfortunately if you're chasing an optimization bug all bets are off and, like Bernd said, you just have to get used to it. cheers, Kris ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Who's insane: gdb or I? 2002-07-03 6:16 Who's insane: gdb or I? Bernd Jendrissek 2002-07-03 6:24 ` Eli Zaretskii @ 2002-07-03 9:29 ` Carlo Wood 2002-07-05 3:05 ` Bernd Jendrissek 2002-07-05 18:23 ` Who's insane: gdb or I? (Answer: I am) Bernd Jendrissek 3 siblings, 0 replies; 6+ messages in thread From: Carlo Wood @ 2002-07-03 9:29 UTC (permalink / raw) To: Bernd Jendrissek; +Cc: gdb On Wed, Jul 03, 2002 at 03:15:47PM +0200, Bernd Jendrissek wrote: > 1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > (gdb) s > 1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; > (gdb) s > 1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > (gdb) s > 1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; Which compiler version are you using? Can you show the *.s file of this part that is being generated? (Add -save-temps to the gcc/g++ line that generates the *.o file; it will also generate a *.s file then). Does the same thing happen when you use -gstabs or -gdwarf-2 instead of just -g? -- Carlo Wood <carlo@alinoe.com> ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Who's insane: gdb or I? 2002-07-03 6:16 Who's insane: gdb or I? Bernd Jendrissek 2002-07-03 6:24 ` Eli Zaretskii 2002-07-03 9:29 ` Carlo Wood @ 2002-07-05 3:05 ` Bernd Jendrissek 2002-07-05 18:23 ` Who's insane: gdb or I? (Answer: I am) Bernd Jendrissek 3 siblings, 0 replies; 6+ messages in thread From: Bernd Jendrissek @ 2002-07-05 3:05 UTC (permalink / raw) To: gdb; +Cc: carlo On Wed, Jul 03, 2002 at 03:15:47PM +0200, Bernd Jendrissek wrote: > 1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > (gdb) s > 1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; > (gdb) s > 1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > (gdb) s > 1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; > (gdb) s > 1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > (gdb) s > 1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; > (gdb) list > 1079 return; > 1080 } > 1081 if (PERMaccessconf->nnrpdoverstats) { > 1082 gettimeofday(&etv, NULL); > 1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > 1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; > 1085 } I then wondered why gdb hops between lines 1083 and 1084 a few times. > if (PERMaccessconf->nnrpdoverstats) { > 804cb25: a1 e8 9b 06 08 mov 0x8069be8,%eax > 804cb2a: 83 78 74 00 cmpl $0x0,0x74(%eax) > 804cb2e: 74 48 je 804cb78 <CMDxover+0x15c> > gettimeofday(&etv, NULL); > 804cb30: 83 c4 f8 add $0xfffffff8,%esp > 804cb33: 6a 00 push $0x0 > 804cb35: 8d 5d d0 lea 0xffffffd0(%ebp),%ebx > 804cb38: 53 push %ebx > 804cb39: e8 b6 d9 ff ff call 804a4f4 <_init+0x780> > OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > 804cb3e: 8b 45 d8 mov 0xffffffd8(%ebp),%eax > 804cb41: 8b 4d d0 mov 0xffffffd0(%ebp),%ecx > 804cb44: 29 c1 sub %eax,%ecx > OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; > 804cb46: 8b 45 dc mov 0xffffffdc(%ebp),%eax > 804cb49: 8b 73 04 mov 0x4(%ebx),%esi > 804cb4c: 69 c9 e8 03 00 00 imul $0x3e8,%ecx,%ecx > 804cb52: 29 c6 sub %eax,%esi > 804cb54: bb d3 4d 62 10 mov $0x10624dd3,%ebx > 804cb59: 89 f0 mov %esi,%eax > 804cb5b: f7 eb imul %ebx,%eax > 804cb5d: 03 0d b0 9b 06 08 add 0x8069bb0,%ecx > 804cb63: c1 fa 06 sar $0x6,%edx > 804cb66: 89 f0 mov %esi,%eax > 804cb68: c1 f8 1f sar $0x1f,%eax > 804cb6b: 29 c2 sub %eax,%edx > 804cb6d: 01 d1 add %edx,%ecx > 804cb6f: 89 0d b0 9b 06 08 mov %ecx,0x8069bb0 > } > 804cb75: 83 c4 10 add $0x10,%esp I am happy with the explanation that I should get used to this when running optimized code under gdb. With a look at the assembly (disassembled from the actual binary) I can convince myself that the alternation between lines 1083 and 1084 is due to fancy instruction scheduling and strength reduction on gcc's part. (gcc 2.95.2 BTW, and I know it's ancient. But it works.) Thanks to all who looked at this. Unless anyone else thinks there's something wrong here, I'm not too bothered about it. At -O2 I think I deserve to be confused by gdb! :) Carlo, do you still want me to look at -gstabs vs. -gdwarf? bernd -- berndj@users.sourceforge.net is probably better to bookmark than any employer-specific email address I may have appearing in the headers. ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Who's insane: gdb or I? (Answer: I am) 2002-07-03 6:16 Who's insane: gdb or I? Bernd Jendrissek ` (2 preceding siblings ...) 2002-07-05 3:05 ` Bernd Jendrissek @ 2002-07-05 18:23 ` Bernd Jendrissek 3 siblings, 0 replies; 6+ messages in thread From: Bernd Jendrissek @ 2002-07-05 18:23 UTC (permalink / raw) To: gdb Okay, I think I'm convinced that this is simply normal -O2 behaviour. On Wed, Jul 03, 2002 at 03:15:47PM +0200, Bernd Jendrissek wrote: > 1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > (gdb) s > 1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; > (gdb) s > 1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > (gdb) s > 1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; > (gdb) s > 1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > (gdb) s > 1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; > (gdb) list > 1079 return; > 1080 } > 1081 if (PERMaccessconf->nnrpdoverstats) { > 1082 gettimeofday(&etv, NULL); > 1083 OVERtime+=(etv.tv_sec - stv.tv_sec) * 1000; > 1084 OVERtime+=(etv.tv_usec - stv.tv_usec) / 1000; > 1085 } For those still interested, here's the assembly generated by gcc -save-temps at -O2. (Complete gcc options: -g -O2 -save-temps) movl PERMaccessconf,%eax cmpl $0,116(%eax) je .L799 .stabn 68,0,1082,.LM674-CMDxover .LM674: addl $-8,%esp pushl $0 leal -48(%ebp),%ebx pushl %ebx call gettimeofday .stabn 68,0,1083,.LM675-CMDxover .LM675: movl -40(%ebp),%eax movl -48(%ebp),%ecx subl %eax,%ecx .stabn 68,0,1084,.LM676-CMDxover .LM676: movl -36(%ebp),%eax movl 4(%ebx),%esi .stabn 68,0,1083,.LM677-CMDxover .LM677: imull $1000,%ecx,%ecx .stabn 68,0,1084,.LM678-CMDxover .LM678: subl %eax,%esi movl $274877907,%ebx movl %esi,%eax imull %ebx .stabn 68,0,1083,.LM679-CMDxover .LM679: addl OVERtime,%ecx .stabn 68,0,1084,.LM680-CMDxover .LM680: sarl $6,%edx movl %esi,%eax sarl $31,%eax subl %eax,%edx addl %edx,%ecx movl %ecx,OVERtime .stabn 68,0,1085,.LM681-CMDxover .LM681: addl $16,%esp .L799: So it appears the bouncing between lines 1083 and 1084 really is due to interleaving of instructions. Thanks for everyone's help; I consider this resolved. -- berndj@users.sourceforge.net is probably better to bookmark than any ^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2002-07-06 1:23 UTC | newest] Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2002-07-03 6:16 Who's insane: gdb or I? Bernd Jendrissek 2002-07-03 6:24 ` Eli Zaretskii 2002-07-03 6:42 ` Kris Warkentin 2002-07-03 9:29 ` Carlo Wood 2002-07-05 3:05 ` Bernd Jendrissek 2002-07-05 18:23 ` Who's insane: gdb or I? (Answer: I am) Bernd Jendrissek
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox