Git Product home page Git Product logo

Comments (5)

Martin2112 avatar Martin2112 commented on May 1, 2024

I looked at this when I was fixing the log internal nodes issue with subtree cache. There is a path where this gets logged that's not an error. I think it might be when new subtrees are created as part of the write.

from trillian.

Martin2112 avatar Martin2112 commented on May 1, 2024

Unless this can be isolated to a well defined error condition I propose that we just remove the log message.

from trillian.

Martin2112 avatar Martin2112 commented on May 1, 2024

The map integration test produced 18658 of these warnings at multiple revisions. Didn't see any from the log integration test. First instances:

I0329 11:15:37.261802    8847 trillian_map_server.go:128] {4659909240010390760}: Writing at revision 1
W0329 11:15:37.327372    8847 subtree_cache.go:217] Unexpectedly reading from within GetNodeHash(): {[190 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 8 256}
W0329 11:15:37.327806    8847 subtree_cache.go:217] Unexpectedly reading from within GetNodeHash(): {[213 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 8 256}
W0329 11:15:37.329070    8847 subtree_cache.go:217] Unexpectedly reading from within GetNodeHash(): {[245 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 8 256}

from trillian.

Martin2112 avatar Martin2112 commented on May 1, 2024

I've looked at this more and it seems like it might be unexpectedly traversing a subtree boundary. The "unexpected" reads are all at depths a multiple of 8, which is the strata depth for the top portion of the map tree. It's not a bug as the read is done anyway after the log complaint but I don't want to delete the log message until we fully understand it.

In this log extract note that the preloading is all for levels in the tree below 8, but the unexpected reads are for level 8, which is not in the same subtree.

I0329 14:54:56.336866    9093 trillian_map_server.go:128] {1985301648847493363}: Writing at revision 1
W0329 14:54:56.427252    9093 subtree_cache.go:211] GetNodes: preloading for: [{[120 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (011110000) 
W0329 14:54:56.427494    9093 subtree_cache.go:211] GetNodes: preloading for: [{[86 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 13 256}] (0101011000000) 
W0329 14:54:56.427580    9093 subtree_cache.go:211] GetNodes: preloading for: [{[74 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (01001010000) 
W0329 14:54:56.427292    9093 subtree_cache.go:211] GetNodes: preloading for: [{[216 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 10 256}] (1101100000) 
W0329 14:54:56.427370    9093 subtree_cache.go:211] GetNodes: preloading for: [{[91 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (01011011000) 
W0329 14:54:56.427643    9093 subtree_cache.go:211] GetNodes: preloading for: [{[21 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (000101010) 
W0329 14:54:56.427450    9093 subtree_cache.go:211] GetNodes: preloading for: [{[189 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 10 256}] (1011110100) 
W0329 14:54:56.427406    9093 subtree_cache.go:211] GetNodes: preloading for: [{[179 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 10 256}] (1011001100) 
W0329 14:54:56.427684    9093 subtree_cache.go:211] GetNodes: preloading for: [{[100 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (011001000) 
W0329 14:54:56.427794    9093 subtree_cache.go:211] GetNodes: preloading for: [{[245 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 10 256}] (1111010100) 
W0329 14:54:56.427814    9093 subtree_cache.go:211] GetNodes: preloading for: [{[70 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 12 256}] (010001100000) 
W0329 14:54:56.427852    9093 subtree_cache.go:211] GetNodes: preloading for: [{[123 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (011110110) 
W0329 14:54:56.427905    9093 subtree_cache.go:211] GetNodes: preloading for: [{[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 12 256}] (000000000000) 
W0329 14:54:56.427913    9093 subtree_cache.go:211] GetNodes: preloading for: [{[175 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 13 256}] (1010111100000) 
W0329 14:54:56.427953    9093 subtree_cache.go:211] GetNodes: preloading for: [{[173 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (10101101000) 
W0329 14:54:56.427986    9093 subtree_cache.go:211] GetNodes: preloading for: [{[168 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (10101000000) 
W0329 14:54:56.428031    9093 subtree_cache.go:211] GetNodes: preloading for: [{[99 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (011000110) 
W0329 14:54:56.428043    9093 subtree_cache.go:211] GetNodes: preloading for: [{[79 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (010011110) 
W0329 14:54:56.428076    9093 subtree_cache.go:211] GetNodes: preloading for: [{[30 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (000111100) 
W0329 14:54:56.428098    9093 subtree_cache.go:211] GetNodes: preloading for: [{[254 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 10 256}] (1111111000) 
W0329 14:54:56.428147    9093 subtree_cache.go:211] GetNodes: preloading for: [{[136 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 14 256}] (10001000000000) 
W0329 14:54:56.428160    9093 subtree_cache.go:211] GetNodes: preloading for: [{[11 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 10 256}] (0000101100) 
W0329 14:54:56.428202    9093 subtree_cache.go:211] GetNodes: preloading for: [{[9 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 10 256}] (0000100100) 
W0329 14:54:56.428230    9093 subtree_cache.go:211] GetNodes: preloading for: [{[202 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (110010100) 
W0329 14:54:56.428293    9093 subtree_cache.go:211] GetNodes: preloading for: [{[140 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (100011000) 
W0329 14:54:56.428304    9093 subtree_cache.go:211] GetNodes: preloading for: [{[190 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (10111110000) 
W0329 14:54:56.428354    9093 subtree_cache.go:211] GetNodes: preloading for: [{[243 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 12 256}] (111100110000) 
W0329 14:54:56.428379    9093 subtree_cache.go:211] GetNodes: preloading for: [{[98 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 10 256}] (0110001000) 
W0329 14:54:56.428427    9093 subtree_cache.go:211] GetNodes: preloading for: [{[14 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 10 256}] (0000111000) 
W0329 14:54:56.428449    9093 subtree_cache.go:211] GetNodes: preloading for: [{[178 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (101100100) 
W0329 14:54:56.428486    9093 subtree_cache.go:211] GetNodes: preloading for: [{[48 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (001100000) 
W0329 14:54:56.428514    9093 subtree_cache.go:211] GetNodes: preloading for: [{[27 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (00011011000) 
W0329 14:54:56.428568    9093 subtree_cache.go:211] GetNodes: preloading for: [{[160 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (10100000000) 
W0329 14:54:56.428573    9093 subtree_cache.go:211] GetNodes: preloading for: [{[149 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (10010101000) 
W0329 14:54:56.428627    9093 subtree_cache.go:211] GetNodes: preloading for: [{[249 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (11111001000) 
W0329 14:54:56.428654    9093 subtree_cache.go:211] GetNodes: preloading for: [{[76 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (01001100000) 
W0329 14:54:56.428708    9093 subtree_cache.go:211] GetNodes: preloading for: [{[78 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (01001110000) 
W0329 14:54:56.428715    9093 subtree_cache.go:211] GetNodes: preloading for: [{[166 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 16 256}] (1010011000000000) 
W0329 14:54:56.428783    9093 subtree_cache.go:211] GetNodes: preloading for: [{[131 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (10000011000) 
W0329 14:54:56.428840    9093 subtree_cache.go:211] GetNodes: preloading for: [{[199 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (110001110) 
W0329 14:54:56.428869    9093 subtree_cache.go:211] GetNodes: preloading for: [{[126 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (01111110000) 
W0329 14:54:56.428949    9093 subtree_cache.go:211] GetNodes: preloading for: [{[124 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (01111100000) 
W0329 14:54:56.428916    9093 subtree_cache.go:211] GetNodes: preloading for: [{[181 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 16 256}] (1011010100000000) 
W0329 14:54:56.428986    9093 subtree_cache.go:211] GetNodes: preloading for: [{[167 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (101001110) 
W0329 14:54:56.429026    9093 subtree_cache.go:211] GetNodes: preloading for: [{[46 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (001011100) 
W0329 14:54:56.429046    9093 subtree_cache.go:211] GetNodes: preloading for: [{[4 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (00000100000) 
W0329 14:54:56.429081    9093 subtree_cache.go:211] GetNodes: preloading for: [{[151 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (100101110) 
W0329 14:54:56.429137    9093 subtree_cache.go:211] GetNodes: preloading for: [{[57 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (00111001000) 
W0329 14:54:56.429191    9093 subtree_cache.go:211] GetNodes: preloading for: [{[213 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (110101010) 
W0329 14:54:56.429202    9093 subtree_cache.go:211] GetNodes: preloading for: [{[217 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (110110010) 
W0329 14:54:56.429261    9093 subtree_cache.go:211] GetNodes: preloading for: [{[26 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 10 256}] (0001101000) 
W0329 14:54:56.429303    9093 subtree_cache.go:211] GetNodes: preloading for: [{[23 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 11 256}] (00010111000) 
W0329 14:54:56.429304    9093 subtree_cache.go:211] GetNodes: preloading for: [{[210 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 9 256}] (110100100) 
W0329 14:54:56.429382    9093 subtree_cache.go:211] GetNodes: preloading for: [{[161 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 12 256}] (101000010000) 
W0329 14:54:56.432240    9093 subtree_cache.go:223] Unexpectedly reading from within GetNodeHash(): {[213 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 8 256} (11010101)
W0329 14:54:56.432932    9093 subtree_cache.go:223] Unexpectedly reading from within GetNodeHash(): {[217 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] 8 256} (11011001)

from trillian.

Martin2112 avatar Martin2112 commented on May 1, 2024

I think I understand this one now. preload() passes a set of nodeIDs for subtrees to storage. Some of these might not exist but it does not create empty cache entries. The "unexpected read" path doesn't know this and requests the subtree from storage again.

from trillian.

Related Issues (20)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.