lisp-project-of-the-day icon indicating copy to clipboard operation
lisp-project-of-the-day copied to clipboard

lack-middleware-accesslog

Open utterances-bot opened this issue 5 years ago • 10 comments

lack-middleware-accesslog

https://40ants.com/lisp-project-of-the-day/2020/06/0106-lack-middleware-accesslog.html

utterances-bot avatar Jun 25 '20 12:06 utterances-bot

Any idea why this doesn't work ?

(builder
 (:accesslog
  :logger (lambda (message) (access-logger message)))
 *web*)

(defun access-logger (message)
  (str:to-file
   (merge-pathnames #P"access.log" *logs-directory*)
   (format nil "~a~%" message)
   :if-exists :append
   :if-does-not-exist :create))

but this works:

(builder
 (:accesslog
  :logger (lambda (message)
            (str:to-file
             (merge-pathnames #P"access.log" *logs-directory*)
             (format nil "~a~%" message)
             :if-exists :append
             :if-does-not-exist :create)))
 *web*)

For the none working case I get a weird hunchentoot error from request handling.

mdbergmann avatar Jun 25 '20 12:06 mdbergmann

For me, the first way also works.

When you are asking such question it helps to add an error's backtrace.

svetlyak40wt avatar Jun 25 '20 13:06 svetlyak40wt

I'm not sure it is the right place here for this. So let me know if I should ask this elsewhere.

Here is a backtrace:

The value "(REQUEST-METHOD GET SCRIPT-NAME  PATH-INFO / SERVER-NAME 192.168.50.101 SERVER-PORT 5000 SERVER-PROTOCOL HTTP/1.1 REQUEST-URI / URL-SCHEME http REMOTE-ADDR 192.168.50.101 REMOTE-PORT 57563 QUERY-STRING NIL RAW-BODY #<FLEXI-IO-STREAM #x302005E9AF0D> CONTENT-LENGTH NIL CONTENT-TYPE NIL CLACK.STREAMING T CLACK.IO #<CLIENT #x302005E9AEBD> HEADERS #<HASH-TABLE :TEST EQUAL size 9/60 #x302005E9A81D>)
" is not of the expected type (OR LIST FUNCTION).
   [Condition of type TYPE-ERROR]

Restarts:
 0: [ABORT-BREAK] Reset this thread
 1: [ABORT] Kill this thread

Backtrace:
 0: (#<STANDARD-METHOD HUNCHENTOOT:MAYBE-INVOKE-DEBUGGER (T)> #<TYPE-ERROR #x302005E9841D>)
 1: (SIGNAL #<TYPE-ERROR #x302005E9841D>)
 2: (CCL::%ERROR #<TYPE-ERROR #x302005E9841D> NIL 82340076)
 3: (CLACK.HANDLER.HUNCHENTOOT::HANDLE-RESPONSE "(REQUEST-METHOD GET SCRIPT-NAME  PATH-INFO / SERVER-NAME 192.168.50.101 SERVER-PORT 5000 SERVER-PROTOCOL HTTP/1.1 REQUEST-URI / URL-SCHEME http REMOTE-ADDR..
 4: (#<STANDARD-METHOD HUNCHENTOOT:ACCEPTOR-DISPATCH-REQUEST (CLACK.HANDLER.HUNCHENTOOT::CLACK-ACCEPTOR T)> #<CLACK-ACCEPTOR (host 0.0.0.0, port 5000)> #<HUNCHENTOOT:REQUEST #x302005E9B45D>)
 5: (#<STANDARD-METHOD HUNCHENTOOT:HANDLE-REQUEST (HUNCHENTOOT:ACCEPTOR HUNCHENTOOT:REQUEST)> #<CLACK-ACCEPTOR (host 0.0.0.0, port 5000)> #<HUNCHENTOOT:REQUEST #x302005E9B45D>)
 6: (#<STANDARD-METHOD HUNCHENTOOT:PROCESS-REQUEST (T)> #<HUNCHENTOOT:REQUEST #x302005E9B45D>)
 7: ((:INTERNAL (HUNCHENTOOT:PROCESS-CONNECTION (HUNCHENTOOT:ACCEPTOR T))))
 8: (HUNCHENTOOT::DO-WITH-ACCEPTOR-REQUEST-COUNT-INCREMENTED #<CLACK-ACCEPTOR (host 0.0.0.0, port 5000)> #<CCL:COMPILED-LEXICAL-CLOSURE (:INTERNAL ..))
 9: (#<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION (HUNCHENTOOT:ACCEPTOR T)> #<CLACK-ACCEPTOR (host 0.0.0.0, port 5000)> #<USOCKET:STREAM-USOCKET #x302005E5E27D>)
10: (CCL::%CALL-NEXT-METHOD (NIL #<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION (HUNCHENTOOT:ACCEPTOR T)> . 82340271))
11: (#<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION :AROUND (HUNCHENTOOT:ACCEPTOR T)> #<CLACK-ACCEPTOR (host 0.0.0.0, port 5000)> #<USOCKET:STREAM-USOCKET #x302005E5E27D>)
12: (CCL::%CALL-NEXT-METHOD (NIL #<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION (HUNCHENTOOT:ACCEPTOR T)> . 82340271))
13: (#<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION :AROUND (CLACK.HANDLER.HUNCHENTOOT::CLACK-ACCEPTOR T)> #<CLACK-ACCEPTOR (host 0.0.0.0, port 5000)> #<USOCKET:STREAM-USOCKET #x302005E5E27D>)
14: (CCL::%%STANDARD-COMBINED-METHOD-DCODE (#<STANDARD-METHOD HUNCHENTOOT:PROCESS-CONNECTION :AROUND (CLACK.HANDLER.HUNCHENTOOT::CLACK-ACCEPTOR T)> ..)) 82340271)
15: (NIL #<Unknown Arguments>)
16: ((:INTERNAL HUNCHENTOOT::PROCESS-CONNECTION% (HUNCHENTOOT::HANDLE-INCOMING-CONNECTION% (HUNCHENTOOT:ONE-THREAD-PER-CONNECTION-TASKMASTER T))) #<CLACK-ACCEPTOR (host 0.0.0.0, port 5000)> #<USOCKET:STRE..
17: (#<STANDARD-METHOD HUNCHENTOOT::HANDLE-INCOMING-CONNECTION% (HUNCHENTOOT:ONE-THREAD-PER-CONNECTION-TASKMASTER T)> #<HUNCHENTOOT:ONE-THREAD-PER-CONNECTION-TASKMASTER #x302005DA388D> #<USOCKET:STREAM-US..
18: ((:INTERNAL (HUNCHENTOOT:CREATE-REQUEST-HANDLER-THREAD (HUNCHENTOOT:ONE-THREAD-PER-CONNECTION-TASKMASTER T))))
19: ((:INTERNAL BORDEAUX-THREADS::BINDING-DEFAULT-SPECIALS))

mdbergmann avatar Jun 25 '20 13:06 mdbergmann

In regards to access-logging with Clack. Is it possible to log more of the request, like any additional HTTP parameters? Or must this be done manually in the routing handlers?

mdbergmann avatar Jun 25 '20 13:06 mdbergmann

I didn't show this in the article, but you also can pass additional argument :formatter to the accesslog middleware – a function for formatting the log message.

Here is how default formatter looks like:

(defun default-formatter (env res now)
  (format nil "~A - [~A] \"~A ~A ~A\" ~A ~A \"~:[-~;~:*~A~]\" \"~:[-~;~:*~A~]\""
          (getf env :remote-addr)
          (local-time:format-timestring nil now :format *time-format*)
          (getf env :request-method)
          (getf env :request-uri)
          (getf env :server-protocol)
          (car res)
          (content-length res)
          (gethash "referer" (getf env :headers))
          (gethash "user-agent" (getf env :headers))))

You can do a function like that and pass it to the acceslog middleware.

svetlyak40wt avatar Jun 25 '20 13:06 svetlyak40wt

About the error

The value "(REQUEST-METHOD GET SCRIPT-NAME  PATH-INFO / SERVER-NAME 192.168.50.101 SERVER-PORT 5000 SERVER-PROTOCOL HTTP/1.1 REQUEST-URI / URL-SCHEME http REMOTE-ADDR 192.168.50.101 REMOTE-PORT 57563 QUERY-STRING NIL RAW-BODY #<FLEXI-IO-STREAM #x302005E9AF0D> CONTENT-LENGTH NIL CONTENT-TYPE NIL CLACK.STREAMING T CLACK.IO #<CLIENT #x302005E9AEBD> HEADERS #<HASH-TABLE :TEST EQUAL size 9/60 #x302005E9A81D>)
" is not of the expected type (OR LIST FUNCTION).
   [Condition of type TYPE-ERROR]

I can't figure out why it can pappen. Seems like a result of some misconfiguration in the app itself.

It might help if you will publish a full text of the reproduceble example somewhere on the GitHub Gist.

svetlyak40wt avatar Jun 25 '20 14:06 svetlyak40wt

If you don't mind, you can have a look here: https://github.com/mdbergmann/cl-swbymabeweb

The relevant files are 'app.lisp', 'src/web.lisp' and 'src/main.lisp'.

mdbergmann avatar Jun 25 '20 14:06 mdbergmann

It is better to debug such issues on a minimal example which reproduces the error.

svetlyak40wt avatar Jun 25 '20 17:06 svetlyak40wt

Yeah, I know. I thought you might spot something. It's pretty much a stock Caveman2 project skeleton.

However, I have little desire to strip it down. Rather I get rid of Clack.

mdbergmann avatar Jun 25 '20 18:06 mdbergmann

Anyway, thanks for looking.

mdbergmann avatar Jun 25 '20 18:06 mdbergmann