Why does DTrace give me invalid-address errors some times and not others?

Question

My program:

typedef struct objc_class {
 struct objc_class *isa;
 struct objc_class *super_class;
 char *name;
 long version;
 long info;
 long instance_size;
 void *ivars;
 void *methodLists;
 void *cache;
 void *protocols;
} *Class;
struct objc_object {
 Class isa;
};

/* Code to extract the class name from arg0 based on a snippet by Bill Bumgarner: http://friday.com/bbum/2008/01/26/objective-c-printing-class-name-from-dtrace/ */

objc$target:NSObject:-init:entry {
 printf("time: %llu\n", timestamp);
 printf("arg0: %p\n", arg0);
 obj = (struct objc_object *)copyin(arg0, sizeof(struct objc_object));
 printf("obj: %p\n", obj);
 printf("obj->isa: %p\n", obj->isa);
 isa = (Class)copyin((user_addr_t)obj->isa, sizeof(struct objc_class));
 printf("isa: %p\n", obj->isa);
 classname = copyinstr((user_addr_t)(isa->name));
 printf("classname: %s\n", classname);
}

Some output:

dtrace: script 'test.d' matched 1 probe
dtrace: error on enabled probe ID 1 (ID 61630: objc5936:NSObject:-init:entry): invalid address (0x90206b98) in action #8 at DIF offset 28
dtrace: error on enabled probe ID 1 (ID 61630: objc5936:NSObject:-init:entry): invalid address (0x90206b98) in action #8 at DIF offset 28
dtrace: error on enabled probe ID 1 (ID 61630: objc5936:NSObject:-init:entry): invalid address (0x90206b98) in action #8 at DIF offset 28
CPU     ID                    FUNCTION:NAME
  0  61630                      -init:entry time: 28391086668386
arg0: 1291ae10
obj: 6f0a1158
obj->isa: a023f360
isa: a023f360
classname: NSBitmapImageRep

  1  61630                      -init:entry time: 28391586872297
arg0: 12943560
obj: 6f4a1158
obj->isa: 2fca0
isa: 2fca0
classname: GrowlApplicationTicket

  1  61630                      -init:entry time: 28391586897807
arg0: 152060
obj: 6f4a1280
obj->isa: 2fe20
isa: 2fe20
classname: GrowlNotificationTicket

  2  61630                      -init:entry time: 28391079142905
arg0: 129482d0
obj: 700a1128
obj->isa: a0014140
isa: a0014140
classname: NSDistributedObjectsStatistics

  2  61630                      -init:entry time: 28391079252640
arg0: 147840
obj: 700a1250
obj->isa: a0014780
isa: a0014780
classname: NSDistantObjectTableEntry

Why the errors? It seems to be the class name (that's the only %s, and I don't get any errors if I remove it), but why does it think some classes' names are invalid pointers?

Is there any way to get the error messages to actually tell me which line of my DTrace program caused a problem?

Is there a way to call object_getClassName instead of doing this structure-inspection dance?

For what it's worth, the program I'm tracing works fine—it's not crashing, so I don't believe that the classes really are broken.

Answer 1

This is my best guess based on the information provided.

DTrace was purposefully designed in such a way as to make DTrace scripts as deterministic as possible. This is why there are no if statements, loops, subroutines (other than the pseudo-subroutines provided by DTrace itself), etc. This is because the code in your DTrace script is running in kernel mode, not user-land as part of the process(es) being traced. In general, the information DTrace has access to is "read-only" (like most generalizations, this is not strictly true), being able to twiddle bits in programs, or the kernel, with something as powerful as DTrace can cause things to go very, very wrong, very very quickly.

Dollars to donuts, the problem you're having is because the page that the pointer points to is not mapped in to core by the VM system. DTrace can only examine information for memory that is in core- it can't double-fault to get the VM system to load in the page.

You can probably help alleviate the problem if you've got an idea of what the classes "should" be and forcing the pages to be mapped in to core by doing a bunch of dummy NSLog() statements that reference the needed classes at some convenient point early in your programs start up.

Answer 2

I haven't entirely tracked this down myself. It's possible that DTrace is trying to resolve some Objective-C symbols. Although DTrace is a dynamic tracing facility it doesn't mesh well with Objective-C dynamically loading things at runtime. When Objective-C does load new classes,etc DTrace has to resolve this and it takes a little time, especially when your app is just starting up. Even if it does get things loaded, and your objc app is still loading new classes onto the objc runtime its possible DTrace could get screwed up and print methods in the wrong order (if you care about seeing the correct order methods are being executed in), print incorrect timing results,etc.

Answer 3

Colin is pretty close to correct.

See:

http://www.friday.com/bbum/2008/01/03/objective-c-using-dtrace-to-trace-messages-to-nil/

More likely than not, you need to set the DYLD_SHARED_REGION environment variable to avoid. dtrace only really works against mapped memory that is actually resident in physical memory.

You can figure out what is missing by using the vmmap command line tool.

Do a vmmap PID on your application after the above failure messages are generated. Looking at the output, see what region the addresses like 0x90206b98 fall into. Given that address, it is likely in a non-writeable shared chunk of memory that probably isn't resident and, thus, dtrace can't read from it.