Arc Forumnew | comments | leaders | submitlogin
1 point by almkglor 6099 days ago | link | parent

Results of a run:

  arc> (profiler-report)
  ((many-r 1522) (wiki-link 84) (formatting 48) (close-br 19)
  (elided-white 12) (bold 10) (italics 7) (nowiki 7) (bolded-text 5) 
  (italicized-text 5) (open-br 5) (ampersand-coded-text 4) 
  (many-format 3) (nowiki-text 2) (ampersand-codes 1) (nowiki-e 0) 
  (alt-r -4) (p-alphadig -4) (seq-r -690))
  nil
O.O? T.T


1 point by raymyers 6099 days ago | link

Dang, I thought I fixed that bug :P

The last line of profiler-exit is supposed to prevent that.

  (def profiler-exit ()
    (let (name ms) (pop *profiler-stack)
      (let total (- (msec) ms)
        (++ (*profiler-times name)
            (- total *profiler-child-time))
        (= *profiler-child-time
           (if *profiler-stack total 0)))))
Did you do something weird, like Control-C out of a profiled call?

-----

1 point by almkglor 6099 days ago | link

No. But if you're talking about weird stuff, well yes: bolded-text and italicized-text also refer back to formatting via delay-parser:

        (*wiki-pp italicized-text
          (seq italics
               (filt in-italics
                     (many:seq (cant-see italics) (delay-parser formatting)))
               italics))
   ...

        (*wiki-pp formatting
          (alt
            (pred [let c (car _)
                    (or (alphadig c)
                        (whitec c)
                        (in c #\, #\.))]
                  anything)
            wiki-link
            bolded-text
            italicized-text
            ampersand-coded-text
            nowiki-text
            (filt [cons (escape:car _) nil] anything)))

-----

1 point by raymyers 6099 days ago | link

Crikey! Do you think delay-parser is the issue? Let me know if you can reproduce this.

-----

1 point by almkglor 6098 days ago | link

I don't think it's 'delay-parser, per se, just the interrecursion: 'formatting calls 'bolded-text calls 'formatting. I think this is what's making the profiler give weird numbers.

-----

1 point by raymyers 6096 days ago | link

I am having trouble to replicating your problem with mutual recursion. I get the expected result with this mutually recursive test. Can you give me an example that reports incorrectly?

  (def foo (li)
    (if li (do (sleep 0.25) (bar (cdr li)) (sleep 0.25))
        (sleep 2)))

  (def bar (li) 
    (if li (do (sleep 0.25) (foo (cdr li)) (sleep 0.25))
        (sleep 1)))

  (profile foo bar)
  (foo '(a a a a a a a))
  (profiler-report)

-----

1 point by almkglor 6096 days ago | link

Hmm. I'll check again later. In the meantime, what I did in the great-grandparent post was just this, on a fresh start:

1. turn on profiling in wiki-arc/wiki-arc.arc, by setting the variable whose name escapes me at the moment to t

2. Load wiki-arc/wiki-arc.arc and (thread (asv)) the server.

3. Load a single test page, with various formatting, including '''a bolded text's attempt to ''confuse the parser''''', [[link]]s, [[sample link|links with different text]]s etc. etc.

4. (profiler-report)

I'll check later on it, and possibly also post the sample wikitext.

-----

1 point by almkglor 6096 days ago | link

Even weirder now:

  ((alt-r 2) (many-r 1) (formatting 0) (close-br 0) (italics 0) (arc-code 0) 
  (wiki-link 0) (open-br 0) (arc-tag-e 0) (bolded-text 0) (nowiki-e 0) 
  (many-format 0) (elided-white 0) (p-alphadig 0) (italicized-text 0) 
  (ampersand-coded-text 0) (ampersand-codes 0) (arc-tag 0) 
  (nowiki-text 0) (nowiki 0) (bold 0) (seq-r -3))
This from a page which Arki reports as having been generated in 1666msec. It's funny, because the total time is 0.

Can you try reproducing the above setup? Maybe it's the threading thing which is bollixing it?

-----