[Python-Dev] New branch for r23c2 work

[Skip Montanaro]

    Skip> It looks like the Mac OS X implementation of getaddrinfo is just
    Skip> dog slow.  I instrumented setipaddr with calls to gettimeofday()
    Skip> to see how long different sections took.  It turns out that
    Skip> getaddrinfo() is hideously slow:

    Stuart> This would be hideously slow by design - Python is sitting idle
    Stuart> while the lookupd directory is queried (you can tell as lookupd
    Stuart> process is chewing CPU).

Yes, thanks for reminding me of that.  I had forgotten that an external
process is involved in name resolution.

    Stuart> I don't think this should affect an Apple release - Python 2.2.0
    Stuart> as shipped with OS X 10.2 has the same behavior.

I think we've concluded that it's okay to ship 2.3 with this problem
unresolved, however I'm completely befuddled at the moment.  I wrote this
simple program:

    #include <sys/time.h>
    #include <sys/types.h>
    #include <sys/socket.h>
    #include <netdb.h>
    #include <stdio.h>

    int
    main(int argc, char **argv) {
            int i;
            struct addrinfo hints, *res;
            int error;
            struct timeval t, u;

            hints.ai_family = AF_INET;
            hints.ai_socktype = SOCK_DGRAM;     /*dummy*/
            hints.ai_flags = AI_PASSIVE;

            printf("start\n");
            for (i=0; i<100; i++) {
                    gettimeofday(&t, NULL);
                    error = getaddrinfo(0, "0", &hints, &res);
                    gettimeofday(&u, NULL);
                    fprintf(stderr, "gtod: %.6f\n",
                            u.tv_sec-t.tv_sec+(u.tv_usec-t.tv_usec)*1e-6);
                    freeaddrinfo(res);
            }
            printf("finish\n");
    }

When run on my Mac, it takes between 2 and 7 microseconds per getaddrinfo
call.  The exact same instrumented call inside socketmodule.c:setipaddr at
line 700 takes about 150 *milli*seconds per call.  I tried eliminating the
Py_{BEGIN,END}_ALLOW_THREADS calls as well as the ACQUIRE and RELEASE of the
getaddrinfo lock.  That had no effect on the call.

I also tweaked the compile like to run just the C preprocessor (gcc -E
instead of gcc -g) and checked the output:

                ...
                hints.ai_family = af;
                hints.ai_socktype = 2;
                hints.ai_flags = 0x00000001;
                { PyThreadState *_save; _save = PyEval_SaveThread();
                PyThread_acquire_lock(netdb_lock, 1);
                gettimeofday(&t, 0);
                error = getaddrinfo(0, "0", &hints, &res);
                gettimeofday(&u, 0);
                fprintf((&__sF[2]), "gtod: %.6f\n",
                        u.tv_sec-t.tv_sec+(u.tv_usec-t.tv_usec)*1e-6);
                PyEval_RestoreThread(_save); }
                ...

otool -L run against both the test program and _socket.so indicate that both
refer to just one shared library (/usr/lib/libSystem.B.dylib), so both
should be calling the same routine.

Another little observation.  I ran the getaddr program (with the loop
cranked up to 10 million iterations) while the top command was running.  The
lookupd process didn't show on the radar at all.  While running the Python
script however, lookupd consumed about 50% of the cpu.

I've added this information to the tracker item.

Skip