some description

chan_log_2.txt

==== start log session ====
  2.298825 SEND on 1: '[9,[{"name":"EMACS-REX","package":"KEYWORD"},[{"name":"FUZZY-COMPLETIONS","package":"SWANK"},"ccl:wi","COMMON-LISP-USER",{"name":"LIMIT","package":"KEYWORD"},200,{"name":"TIME-LIMIT-IN-MSEC","package":"KEYWORD"},500],"COMMON-LISP-USER",true]]
'
  2.299254 : looking for messages on channels
  2.486965 RECV on 1: '[9,[{"name":"RETURN","package":"KEYWORD"},[{"name":"OK","package":"KEYWORD"},[[["ccl:with-xref","60.34",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-cstrs","60.20",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-macptrs","59.99",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-read-lock","59.85",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-write-lock","59.80",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-open-socket","59.75",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-lock-grabbed","59.71",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-added-methods","59.67",[[0,"ccl"],[4,"wi"]],"--------"],["ccl:with-encoded-cstrs","59.67",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-input-timeout","59.67",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-string-vector","59.67",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:without-interrupts","59.67",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-filename-cstrs","59.64",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-output-timeout","59.64",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-terminal-input","59.64",[[0'
  2.487076 on 1: Incomplete message - wait for more
  2.487208 RECV on 1: ',"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-output-to-vector","59.59",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-input-from-vector","59.56",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-interrupts-enabled","59.54",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-pointer-to-ivector","59.54",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:without-compiling-code-coverage","59.42",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-decoding-problems-as-errors","59.41",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-encoding-problems-as-errors","59.41",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:without-duplicate-definition-warnings","59.36",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:%word-to-int","58.29",[[0,"ccl"],[5,"w"],[13,"i"]],"-f------"],["ccl:*warn-if-redefine*","57.97",[[0,"ccl"],[5,"w"],[10,"i"]],"b-------"],["ccl:who-indirectly-calls","57.91",[[0,"ccl"],[4,"w"],[8,"i"]],"-f------"],["ccl:*warn-if-redefine-kernel*","57.80",[[0,"ccl"],[5,"w"],[10,"i"]],"b-------"],["ccl:stream-write-ivector","55.91",[[0,"ccl"],[11,"w"],[17,"i"]],"-fg-----"],["ccl:process-wait-with-timeout","55.80",[[0,"ccl"],[17,"wi"]],"-f------"],["ccl:*check-call-next-method-with-args*","55.69",[[0,"ccl"],[28,"wi"]],"b-------"],["ccl:who-binds","51.64",[[0,"ccl"],[4,"w"],[9,"i"]],"-f------"],["ccl:whitespacep","51.39",[[0,"ccl"],[4,"w"],[6,"i"]],"-f------"],["ccl:wait-for-signal","51.10",[[0,"ccl"],[4,"w"],[6,"i"]],"-f------"],["ccl:wait-on-semaphore","51.01",[[0,"ccl"],[4,"w"],[6,"i"]],"-f------"],["ccl:who-directly-calls","50.97",[[0,"ccl"],[4,"w"],[9,"i"]],"-f------"],["ccl:writer-method-class","50.94",[[0,"ccl"],[4,"w"],[6,"i"]],"-fg-----"],["ccl:write-coverage-to-file","50.86",[[0,"ccl"],[4,"w"],[6,"i"]],"-f------"],["ccl:process-wait","49.29",[[0,"ccl"],[12,"w"],[14,"i"]],"-f------"],["ccl:style-warning","49.22",[[0,"ccl"],[10,"w"],[14,"i"]],"---ct---"],["ccl:read-write-lock","49.10",[[0,"ccl"],[9,"w"],[11,"i"]],"---ct---"],["ccl:compiler-warning","49.05",[[0,"ccl"],[13,"w"],[17,"i"]],"---ct---"],["ccl:stream-write-byte","49.01",[[0,"ccl"],[11,"w"],[13,"i"]],"-fg-----"],["ccl:stream-write-char","49.01",[[0,"ccl"],[11,"w"],[13,"i"]],"-fg-----"],["ccl:stream-write-list","49.01",[[0,"ccl"],[11,"w"],[13,"i"]],"-fg-----"],["ccl:process-input-wait","48.97",[[0,"ccl"],[18,"w"],[20,"i"]],"-f------"],["ccl:*break-on-warnings*","48.94",[[0,"ccl"],[14,"w"],[18,"i"]],"b-------"],["ccl:process-output-wait","48.94",[[0,"ccl"],[19,"w"],[21,"i"]],"-f------"],["ccl:set-file-write-date","48.94",[[0,"ccl"],[13,"w"],[15,"i"]],"--------"],["ccl:stream-write-string","48.94",[[0,"ccl"],[11,"w"],[13,"i"]],"-fg-----"],["ccl:stream-write-vector","48.94",[[0,"ccl"],[11,"w"],[13,"i"]],"-fg-----"],["ccl:make-read-write-lock","48.91",[[0,"ccl"],[14,"w"],[16,"i"]],"-f------"],["ccl:standard-writer-method","48.86",[[0,"ccl"],[13,"w"],[15,"i"]],"---ct---"],["ccl:report-compiler-warning","48.84",[[0,"ccl"],[20,"w"],[24,"i"]],"-f------"],["ccl:slot-definition-writers","48.84",[[0,"ccl"],[20,"w"],[22,"i"]],"-fg-----"],["ccl:timed-wait-on-semaphore","48.84",[[0,"ccl"],[10,"w"],[12,"i"]],"-f------"],["ccl:*merge-'
  2.487218 : looking for messages on channels
  2.487538 on 1: still waiting on incomplete message
  2.487609 RECV on 1: 'compiler-warnings*","48.80",[[0,"ccl"],[20,"w"],[24,"i"]],"b-------"],["ccl:compiler-warning-source-note","48.76",[[0,"ccl"],[13,"w"],[17,"i"]],"-fg-----"],["ccl:compiler-warning-function-name","48.73",[[0,"ccl"],[13,"w"],[17,"i"]],"-fg-----"],["ccl:*backtrace-show-internal-frames*","48.71",[[0,"ccl"],[18,"w"],[20,"i"]],"b-------"],["ccl:*break-loop-when-uninterruptable*","48.70",[[0,"ccl"],[16,"w"],[23,"i"]],"b-------"],["ccl:show-documentation","41.97",[[0,"ccl"],[7,"w"],[19,"i"]],"--------"],["ccl:new-compiler-policy","41.94",[[0,"ccl"],[6,"w"],[12,"i"]],"-f------"],["ccl:choose-new-file-dialog","41.86",[[0,"ccl"],[13,"w"],[16,"i"]],"-f------"],["quicklisp-client:where-is-system","36.43",[[3,"c"],[10,"cl"],[17,"w"],[23,"i"]],"-f------"],["quicklisp-client:write-asdf-manifest-file","29.15",[[3,"c"],[10,"cl"],[17,"w"],[19,"i"]],"-f------"]],null]]]]
'
  2.487618 : looking for messages on channels
  2.487657 : ERROR: E474: Invalid argument
  2.487667 ERR on 1: Decoding failed - discarding input
  5.520443 : looking for messages on channels
  5.520508 : ERROR: E474: Invalid argument
  5.520522 ERR on 1: Decoding failed - discarding input
  5.520549 : looking for messages on channels
  5.524385 SEND on 1: '[10,[{"name":"EMACS-REX","package":"KEYWORD"},[{"name":"FUZZY-COMPLETIONS","package":"SWANK"},"ccl:wi","COMMON-LISP-USER",{"name":"LIMIT","package":"KEYWORD"},200,{"name":"TIME-LIMIT-IN-MSEC","package":"KEYWORD"},500],"COMMON-LISP-USER",true]]
'
  5.524834 : looking for messages on channels
  5.668195 RECV on 1: '[10,[{"name":"RETURN","package":"KEYWORD"},[{"name":"OK","package":"KEYWORD"},[[["ccl:with-xref","60.34",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-cstrs","60.20",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-macptrs","59.99",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-read-lock","59.85",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-write-lock","59.80",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-open-socket","59.75",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-lock-grabbed","59.71",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-added-methods","59.67",[[0,"ccl"],[4,"wi"]],"--------"],["ccl:with-encoded-cstrs","59.67",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-input-timeout","59.67",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-string-vector","59.67",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:without-interrupts","59.67",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-filename-cstrs","59.64",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-output-timeout","59.64",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-terminal-input","59.64",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-output-to-vector","59.59",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-input-from-vector","59.56",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-interrupts-enabled","59.54",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-pointer-to-ivector","59.54",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:without-compiling-code-coverage","59.42",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-decoding-problems-as-errors","59.41",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:with-encoding-problems-as-errors","59.41",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:without-duplicate-definition-warnings","59.36",[[0,"ccl"],[4,"wi"]],"-f---m--"],["ccl:%word-to-int","58.29",[[0,"ccl"],[5,"w"],[13,"i"]],"-f------"],["ccl:*warn-if-redefine*","57.97",[[0,"ccl"],[5,"w"],[10,"i"]],"b-------"],["ccl:who-indirectly-calls","57.91",[[0,"ccl"],[4,"w"],[8,"i"]],"-f------"],["ccl:*warn-if-redefine-kernel*","57.80",[[0,"ccl"],[5,"w"],[10,"i"]],"b-------"],["ccl:stream-write-ivector","55.91",[[0,"ccl"],[11,"w"],[17,"i"]],"-fg-----"],'
  5.668389 on 1: Incomplete message - wait for more
  5.668547 RECV on 1: '["ccl:process-wait-with-timeout","55.80",[[0,"ccl"],[17,"wi"]],"-f------"],["ccl:*check-call-next-method-with-args*","55.69",[[0,"ccl"],[28,"wi"]],"b-------"],["ccl:who-binds","51.64",[[0,"ccl"],[4,"w"],[9,"i"]],"-f------"],["ccl:whitespacep","51.39",[[0,"ccl"],[4,"w"],[6,"i"]],"-f------"],["ccl:wait-for-signal","51.10",[[0,"ccl"],[4,"w"],[6,"i"]],"-f------"],["ccl:wait-on-semaphore","51.01",[[0,"ccl"],[4,"w"],[6,"i"]],"-f------"],["ccl:who-directly-calls","50.97",[[0,"ccl"],[4,"w"],[9,"i"]],"-f------"],["ccl:writer-method-class","50.94",[[0,"ccl"],[4,"w"],[6,"i"]],"-fg-----"],["ccl:write-coverage-to-file","50.86",[[0,"ccl"],[4,"w"],[6,"i"]],"-f------"],["ccl:process-wait","49.29",[[0,"ccl"],[12,"w"],[14,"i"]],"-f------"],["ccl:style-warning","49.22",[[0,"ccl"],[10,"w"],[14,"i"]],"---ct---"],["ccl:read-write-lock","49.10",[[0,"ccl"],[9,"w"],[11,"i"]],"---ct---"],["ccl:compiler-warning","49.05",[[0,"ccl"],[13,"w"],[17,"i"]],"---ct---"],["ccl:stream-write-byte","49.01",[[0,"ccl"],[11,"w"],[13,"i"]],"-fg-----"],["ccl:stream-write-char","49.01",[[0,"ccl"],[11,"w"],[13,"i"]],"-fg-----"],["ccl:stream-write-list","49.01",[[0,"ccl"],[11,"w"],[13,"i"]],"-fg-----"],["ccl:process-input-wait","48.97",[[0,"ccl"],[18,"w"],[20,"i"]],"-f------"],["ccl:*break-on-warnings*","48.94",[[0,"ccl"],[14,"w"],[18,"i"]],"b-------"],["ccl:process-output-wait","48.94",[[0,"ccl"],[19,"w"],[21,"i"]],"-f------"],["ccl:set-file-write-date","48.94",[[0,"ccl"],[13,"w"],[15,"i"]],"--------"],["ccl:stream-write-string","48.94",[[0,"ccl"],[11,"w"],[13,"i"]],"-fg-----"],["ccl:stream-write-vector","48.94",[[0,"ccl"],[11,"w"],[13,"i"]],"-fg-----"],["ccl:make-read-write-lock","48.91",[[0,"ccl"],[14,"w"],[16,"i"]],"-f------"],["ccl:standard-writer-method","48.86",[[0,"ccl"],[13,"w"],[15,"i"]],"---ct---"],["ccl:report-compiler-warning","48.84",[[0,"ccl"],[20,"w"],[24,"i"]],"-f------"],["ccl:slot-definition-writers","48.84",[[0,"ccl"],[20,"w"],[22,"i"]],"-fg-----"],["ccl:timed-wait-on-semaphore","48.84",[[0,"ccl"],[10,"w"],[12,"i"]],"-f------"],["ccl:*merge-compiler-warnings*","48.80",[[0,"ccl"],[20,"w"],[24,"i"]],"b-------"],["ccl:compiler-warning-source-note","48.76",[[0,"ccl"],[13,"w"],[17,"i"]],"-fg-----"],["ccl:compiler-warning-function-name","48.73",[[0,"ccl"],[13,"w"],[17,"i"]],"-fg-----"],["ccl:*backtrace-show-internal-frames*","48.71",[[0,"ccl"],[18,"w"],[20,"i"]],"b-------"],["ccl:*break-loop-when-uninterruptable*","48.70",[[0,"ccl"],[16,"w"],[23,"i"]],"b-------"],["ccl:show-documentation","41.97",[[0,"ccl"],[7,"w"],[19,"i"]],"--------"],["ccl:new-compiler-policy","41.94",[[0,"ccl"],[6,"w"],[12,"i"]],"-f------"],["ccl:choose-new-file-dialog","41.86",[[0,"ccl"],[13,"w"],[16,"i"]],"-f------"],["quicklisp-client:where-is-system","36.43",[[3,"c"],[10,"cl"],[17,"w"],[23,"i"]],"-f------"],["quicklisp-client:write-asdf-manifest-file","29.15",[[3,"c"],[10,"cl"],[17,"w"],[19,"i"]],"-f------"]],null]]]]
'
  5.668557 : looking for messages on channels
  5.669005 on 1: Getting JSON message 10
  5.669036 on 1: Invoking one-time callback vlime#SimpleSendCB
  7.383434 : looking for messages on channels
  8.088398 : ERROR: E803: ID not found: 3
  8.161255 : looking for messages on channels