public inbox for goredo-devel@lists.cypherpunks.ru
Atom feed

• * OOD checking done too eagerly
         [not found] <87sg6t80s8.fsf@paris.i-did-not-set--mail-host-address--so-tickle-me>
  @ 2021-01-22 15:23 ` spacefrogg-goredo
    2021-01-22 16:12   ` Sergey Matveev
    0 siblings, 1 reply; 3+ messages in thread
  From: spacefrogg-goredo @ 2021-01-22 15:23 UTC (permalink / raw)
    To: goredo-devel
  
  I was just testing 1.0.0 (size checking! :) and
  noticed something odd.
  
  I believe OOD checking is done too eagerly and to deeply, as I'd like to
  show in a small case.
  The dependency chain is as follows:
  c.do -> b.do -> a.do -> x
  with a, b and c being built with redo and x being a source. Each is just
  a copy of its dependency.
  After building c, to populate the dependency database, x is being
  modified. Now, running `redo -d c` again produces the following trace:
  
  ```
  [30328] dbg  [53277686-f322-4fc4-36df-b66997ca2441] run: redo [c] cwd:/tmp/goredo dirprefix:
  [30328] js   release from initial fill
  [30328] dbg  collecting deps
  [30328] dbg  building 1 targets: [c]
  [30328] lock LOCK_NB: /tmp/goredo/.redo/c.lock
  [30328] dbg  ifchange: /tmp/goredo/.redo/.redo.c.dep.2157eaa2 <- c.do
  [30328] wait c
  [30328] dbg  sh: c: /bin/sh [-e c.do c c .redo.c.21594a82.3] cwd:/tmp/goredo dirprefix:
  [30328] js   acquire for sh: c: /bin/sh [-e c.do c c .redo.c.21594a82.3] cwd:/tmp/goredo dirprefix:
  [30328] js   acquired for sh: c: /bin/sh [-e c.do c c .redo.c.21594a82.3] cwd:/tmp/goredo dirprefix:
  [30328] dbg  c runs [30333]
  [30334] dbg  . [53277686-f322-4fc4-36df-b66997ca2441] run: redo-ifchange [b] cwd:/tmp/goredo dirprefix:
  [30334] js   . release from ifchange entered
  [30334] dbg  . collecting deps
  [30334] dbg  . building 1 targets: [b]
  [30334] dbg  . ood: b checking
  [30334] dbg  . ood: b -> b.do: checking
  [30334] dbg  . ood: b -> b.do: same inode
  [30334] dbg  . ood: b -> b.do: is source
  [30334] dbg  . ood: b -> a: checking
  [30334] dbg  . ood: b -> a: same inode
  [30334] dbg  . ood: . a checking
  [30334] dbg  . ood: . a -> a.do: checking
  [30334] dbg  . ood: . a -> a.do: same inode
  [30334] dbg  . ood: . a -> a.do: is source
  [30334] dbg  . ood: . a -> x: checking
  [30334] dbg  . ood: . a -> x: size differs
  [30334] dbg  . ood: . a: true
  [30334] dbg  . ood: b -> a: ood
  [30334] dbg  . ood: b: true
  [30334] lock . LOCK_NB: /tmp/goredo/.redo/b.lock
  [30334] dbg  . ifchange: /tmp/goredo/.redo/.redo.b.dep.2188c262 <- b.do
  [30334] wait . b
  [30334] dbg  . sh: b: /bin/sh [-e b.do b b .redo.b.218bbe4a.3] cwd:/tmp/goredo dirprefix:
  [30334] js   . acquire for sh: b: /bin/sh [-e b.do b b .redo.b.218bbe4a.3] cwd:/tmp/goredo dirprefix:
  [30334] js   . acquired for sh: b: /bin/sh [-e b.do b b .redo.b.218bbe4a.3] cwd:/tmp/goredo dirprefix:
  [30334] dbg  . b runs [30341]
  [30342] dbg  . . [53277686-f322-4fc4-36df-b66997ca2441] run: redo-ifchange [a] cwd:/tmp/goredo dirprefix:
  [30342] js   . . release from ifchange entered
  [30342] dbg  . . collecting deps
  [30342] dbg  . . building 1 targets: [a]
  [30342] dbg  . . ood: a checking
  [30342] dbg  . . ood: a -> a.do: checking
  [30342] dbg  . . ood: a -> a.do: same inode
  [30342] dbg  . . ood: a -> a.do: is source
  [30342] dbg  . . ood: a -> x: checking
  [30342] dbg  . . ood: a -> x: size differs
  [30342] dbg  . . ood: a: true
  ...
  ```
  So, process 30334 (redo-ifchange b) runs the complete dependency
  chain down to the source x, determining that b must be OOD.
  
  This is repeated in 30342 (redo-ifchange a).
  
  The problem is, the dependency chain behind a could be arbitrarily
  large, forcing redo to do this expensive calculation unnecessarily
  often.
  
  What the log should look like (in my opinion) is:
  ```
  [30328] dbg  [53277686-f322-4fc4-36df-b66997ca2441] run: redo [c] cwd:/tmp/goredo dirprefix:
  [30328] js   release from initial fill
  [30328] dbg  collecting deps
  [30328] dbg  building 1 targets: [c]
  [30328] lock LOCK_NB: /tmp/goredo/.redo/c.lock
  [30328] dbg  ifchange: /tmp/goredo/.redo/.redo.c.dep.2157eaa2 <- c.do
  [30328] wait c
  [30328] dbg  sh: c: /bin/sh [-e c.do c c .redo.c.21594a82.3] cwd:/tmp/goredo dirprefix:
  [30328] js   acquire for sh: c: /bin/sh [-e c.do c c .redo.c.21594a82.3] cwd:/tmp/goredo dirprefix:
  [30328] js   acquired for sh: c: /bin/sh [-e c.do c c .redo.c.21594a82.3] cwd:/tmp/goredo dirprefix:
  [30328] dbg  c runs [30333]
  [30334] dbg  . [53277686-f322-4fc4-36df-b66997ca2441] run: redo-ifchange [b] cwd:/tmp/goredo dirprefix:
  [30334] js   . release from ifchange entered
  # Immediately enter dependency c.do -> b.do without checking
  [30334] lock . LOCK_NB: /tmp/goredo/.redo/b.lock
  [30334] dbg  . ifchange: /tmp/goredo/.redo/.redo.b.dep.2188c262 <- b.do
  [30334] wait . b
  [30334] dbg  . sh: b: /bin/sh [-e b.do b b .redo.b.218bbe4a.3] cwd:/tmp/goredo dirprefix:
  [30334] js   . acquire for sh: b: /bin/sh [-e b.do b b .redo.b.218bbe4a.3] cwd:/tmp/goredo dirprefix:
  [30334] js   . acquired for sh: b: /bin/sh [-e b.do b b .redo.b.218bbe4a.3] cwd:/tmp/goredo dirprefix:
  [30334] dbg  . b runs [30341]
  # Immediately enter the dependency chain b.do -> a.do without checking
  [30342] dbg  . . [53277686-f322-4fc4-36df-b66997ca2441] run: redo-ifchange [a] cwd:/tmp/goredo dirprefix:
  [30342] js   . . release from ifchange entered
  [30342] dbg  . . collecting deps
  [30342] dbg  . . building 1 targets: [a]
  [30342] dbg  . . ood: a checking
  [30342] dbg  . . ood: a -> a.do: checking
  [30342] dbg  . . ood: a -> a.do: same inode
  [30342] dbg  . . ood: a -> a.do: is source
  [30342] dbg  . . ood: a -> x: checking
  [30342] dbg  . . ood: a -> x: size differs
  [30342] dbg  . . ood: a: true
  # Back in `redo-ifchange b`, check if running redo-* actually forced `a` OOD
  [30334] dbg  . collecting deps
  [30334] dbg  . building 1 targets: [b]
  [30334] dbg  . ood: b checking
  [30334] dbg  . ood: b -> b.do: checking
  [30334] dbg  . ood: b -> b.do: same inode
  [30334] dbg  . ood: b -> b.do: is source
  [30334] dbg  . ood: b -> a: checking
  # Now a's size will also differ.
  [30334] dbg  . ood: b -> a: size differs
  [30334] dbg  . ood: b -> a: ood
  [30334] dbg  . ood: b: true
  # This is no longer necessary. If a is still current, we're done.
  # [30334] dbg  . ood: . a checking
  # [30334] dbg  . ood: . a -> a.do: checking
  # [30334] dbg  . ood: . a -> a.do: same inode
  # [30334] dbg  . ood: . a -> a.do: is source
  # [30334] dbg  . ood: . a -> x: checking
  # [30334] dbg  . ood: . a -> x: size differs
  # [30334] dbg  . ood: . a: true
  # [30334] dbg  . ood: b -> a: ood
  # [30334] dbg  . ood: b: true
  ```
  As you can see, this cuts down the complete second dependency check to a
  single level in the tree hierarchy.
  
  The only reason for a target to become OOD is that its immediate
  dependencies are OOD. So, this cuts down a quadratic number of checks to
  a linear number.
  
  –Michael
  
  ^ permalink raw reply	[flat|nested] 3+ messages in thread

• • * Re: OOD checking done too eagerly
      2021-01-22 15:23 ` OOD checking done too eagerly spacefrogg-goredo
    @ 2021-01-22 16:12   ` Sergey Matveev
      2021-01-22 16:24     ` Sergey Matveev
      0 siblings, 1 reply; 3+ messages in thread
    From: Sergey Matveev @ 2021-01-22 16:12 UTC (permalink / raw)
      To: goredo-devel
    
    [-- Attachment #1: Type: text/plain, Size: 1051 bytes --]
    
    Greetings!
    
    *** spacefrogg-goredo@spacefrogg•net [2021-01-22 16:23]:
    >So, process 30334 (redo-ifchange b) runs the complete dependency
    >chain down to the source x, determining that b must be OOD.
    >[...]
    >The problem is, the dependency chain behind a could be arbitrarily
    >large, forcing redo to do this expensive calculation unnecessarily
    >often.
    
    All redo-ifchange instances do the same OOD detection again, because
    they do not share already made (by another instance) OOD-decisions.
    
    I completely agreed that they are unnecessary and relatively expensive
    at least because of continuous state files opening and reading. Of
    course because of filesystem's metadata cache, there should be no
    additional disk activity, but burnt CPU cycles and context switches
    because of syscalls.
    
    Currently, I have no plans in that direction, because it is far from
    being the bottleneck. But some day it should be optimized of course.
    
    -- 
    Sergey Matveev (http://www.stargrave.org/)
    OpenPGP: CF60 E89A 5923 1E76 E263  6422 AE1A 8109 E498 57EF
    
    [-- Attachment #2: signature.asc --]
    [-- Type: application/pgp-signature, Size: 833 bytes --]
    
    ^ permalink raw reply	[flat|nested] 3+ messages in thread

  • • * Re: OOD checking done too eagerly
        2021-01-22 16:12   ` Sergey Matveev
      @ 2021-01-22 16:24     ` Sergey Matveev
        0 siblings, 0 replies; 3+ messages in thread
      From: Sergey Matveev @ 2021-01-22 16:24 UTC (permalink / raw)
        To: goredo-devel
      
      [-- Attachment #1: Type: text/plain, Size: 374 bytes --]
      
      *** Sergey Matveev [2021-01-22 19:12]:
      >Currently, I have no plans in that direction, because it is far from
      >being the bottleneck. But some day it should be optimized of course.
      
      Anyway it seems not a big and complex change, so I will try to do that soon.
      
      -- 
      Sergey Matveev (http://www.stargrave.org/)
      OpenPGP: CF60 E89A 5923 1E76 E263  6422 AE1A 8109 E498 57EF
      
      [-- Attachment #2: signature.asc --]
      [-- Type: application/pgp-signature, Size: 833 bytes --]
      
      ^ permalink raw reply	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2021-01-22 16:24 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
     [not found] <87sg6t80s8.fsf@paris.i-did-not-set--mail-host-address--so-tickle-me>
2021-01-22 15:23 ` OOD checking done too eagerly spacefrogg-goredo
2021-01-22 16:12   ` Sergey Matveev
2021-01-22 16:24     ` Sergey Matveev