[Larceny-users] is this a brain-problem or a bug?

[David Rush]

Hi there,

I have been working with the socket interface on Unix in an attempt to
build a native FCGI module for Larceny, and I am frankly stumped. As
far as I can tell, I have two programs which should be functionally
identical. The difference is that one is written in C using the socket
interface directly and the other is written in Larceny, using the FFI.

So the C code:

#include <fastcgi.h>
#include <stdio.h>
#include <sys/types.h>
#include <sys/socket.h>
#include <sys/un.h>
#include <unistd.h>
#include <stdarg.h>
#include <stdlib.h>
#include <string.h>

int main(int c, char** v) {
    struct sockaddr_un addr;
    socklen_t addrlen = 0;
    int cx = 0;
    FILE* log = fopen("raw-fcgi.log", "w");
    fprintf(log, "started FCGI process\n");
    fflush(log);

    addr.sun_family = AF_UNIX;
    for(cx = accept(FCGI_LISTENSOCK_FILENO, (struct sockaddr*)&addr, &addrlen);
        cx >= 0;
        cx = accept(FCGI_LISTENSOCK_FILENO, (struct sockaddr*)&addr,
&addrlen)) {
        FCGI_Header hdr;
        fprintf(log, "got a request, sockaddr family = %d\n", addr.sun_family);
        fflush(log);
        read(cx, (char*)&hdr, sizeof(hdr));

        fprintf(log, "  version = %d\n", hdr.version);
        fprintf(log, "  type = %d\n", hdr.type);
        fprintf(log, "  reqID(B1) = %d\n", hdr.requestIdB1);
        fprintf(log, "  reqID(B0) = %d\n", hdr.requestIdB0);
        fprintf(log, "  reqID = %d\n", hdr.requestIdB1 * 256 + hdr.requestIdB0);
        fprintf(log, "  length(B1) = %d\n", hdr.contentLengthB1);
        fprintf(log, "  length(B0) = %d\n", hdr.contentLengthB0);
        fprintf(log, "  length = %d\n", hdr.contentLengthB1 * 256 +
hdr.contentLengthB0);
        fflush(log);
        close(cx); }

    fprintf(log, "all done\n");
    return 0; }

produces the the following output in raw-fcgi.log

started FCGI process
got a request, sockaddr family = 1
  version = 1
  type = 1
  reqID(B1) = 0
  reqID(B0) = 1
  reqID = 1
  length(B1) = 0
  length(B0) = 8
  length = 8

and the larceny code:

(require 'foreign-ctools)
(require 'foreign-stdlib)
(require 'socket)
(require 'time)
(require 'srfi-9)


(define (ftimestamp)
  (call-with-values current-utc-time
    (lambda (secs fracs)
      (let ((fracs* (number->string fracs)))
        (call-with-output-string
         (lambda (p)
           (display secs p)
           (display #\. p)
           (display (make-string (- 6 (string-length fracs*)) #\0) p)
           (display fracs* p)
           )))
      )))


(define (flog s)
  (let ((entry
         (call-with-output-string
          (lambda (p)
            (display `(,(ftimestamp)
                       , at s) p)
            (newline p)
            )))
        (f ((foreign-procedure "fopen" '(string string) 'void*)
"fcgi.log" "a")))
    ((foreign-procedure "fputs" '(string void*) 'int) entry f)
    ((foreign-procedure "fclose" '(void*) 'void) f)
    (display entry (current-output-port))
    (display entry (current-error-port))
    ))


(define-c-struct ("struct sockaddr_un" make-sockaddr_un
                  (include<> "sys/un.h"))
  ("sun_family"
    (sockaddr_in.sun_family         %get-ushort))
  ("sun_path"
    (sockaddr_in.sun_path           %get-string))
  )


(define (fastcgi argv)
  (flog `(starting fcgi listen process))
  (let accept-requests ()
    (let ((addr         (make-sockaddr_un))
          (addrlen      (make-bytevector sizeof:int)))
      (flog `(got the blinking structures allocated))
      (let ((s ((foreign-procedure "accept" '(int boxed boxed) 'int)
                0 addr addrlen)))
        (flog `(received connection on ,s))
        (let* ((bytes (make-bytevector 8))
               (got ((foreign-procedure "read" '(int boxed int) int)
                     fd bytes 8)))
          (flog `(read ,got header bytes from ,fd))
          (if (>= got 8)
              (let ((version (bytevector-ref bytes 0))
                    (type (bytevector-ref bytes 1))
                    (id (+ (bytevector-ref bytes 2)
                           (* 256 (bytevector-ref bytes 3))))
                    (length (+ (bytevector-ref bytes 4)
                               (* 256 (bytevector-ref bytes 5))))
                    (padding (bytevector-ref bytes 6)))
                (flog `((version ,version)
                        (type ,type)
                        (request-id ,id)
                        (length ,length))))
              (flog `(no header))
              ))
        (close-output-port out)
        (close-input-port in)
        (flog `(finished transaction))
        (accept-requests)
        )))
  (flog `(all done now))
  (exit 0)
  )

(dump-heap "fcgi.image" fastcgi)
(exit 0)

When appropriately packaged up and run produces the following output
in fcgi.log (timestamps are seconds.micros)

(1199729962.355512 starting fcgi listen process)
(1199729962.400555 got the blinking structures allocated)
(1199729962.406820 received connection on 4)
(1199729971.981496 starting fcgi listen process)
(1199729971.992796 got the blinking structures allocated)

which since I don't print the PIDs to the log makes it a little bit
hard to interpret, but I am fairly convinced (by looking at the server
error logs and ps output) that what is happening that the original
FCGI process starts and receives a connection, then hangs trying to
read from that connection. When the FCGI watchdog in the Apache server
notices the hung process it starts another instance (usually after
about 10 seconds).

Now it is clear from the raw-fcgi.c output that the Apache FCGI module
is using Unix domain sockets to talk to the FCGI process, and I'm
wondering if this is a case that is somehow broken in larceny (the
socket.sch code pretty clearly only knows about AF_INET), or if there
is some other I/O configuration difference between the Larceny
run-time and the raw C code.

Can anybody point me in the right direction here? This has been
extremely hard to debug, since - for reasons I do not fully understand
- my 32-bit larceny image can't load the socket library on my x86_64
system which means I am debugging remotely on Dreamhost's servers
underneath the Apache server. Talk about debugging at the end of a
ten-foot pole!

Thanks in advance -

david rush
-- 
Once you label me, you negate me
    - Soren Kierkegaard