Comments (5)
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.
Unless this can be isolated to a well defined error condition I propose that we just remove the log message.
from trillian.
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.
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.
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)
- KeepAlive in etcd client cannot ensure the permanent validity of lease
- Brainstorming: Verkle Tree support in Trillian (constant-sized proofs) HOT 1
- Would there be any interest in more k8s "native" tooling for integration testing? HOT 6
- Unable to create a tree in Trillian log mysql database HOT 4
- Bazel not building
- MySQL: World-writable config warning during startup
- Trillian log server and signer config file does not allow comments HOT 1
- Tag a new release with transparency-dev/merkle extracted HOT 4
- Drop dependency from certificate-transparency-go HOT 1
- Scripts and documentation still refer to pre-Go-module practices HOT 1
- Build and use image for ./examples/deployment/kubernetes/createtree HOT 1
- defense against split view attacks HOT 3
- Cleanup: remove `tree_ids_with_no_ephemeral_nodes` flag after it is the default behavior
- Bump golangci-lint and remove //nolint comments in experimental/batchmap/cmd/verify/verify.go
- Are these the correct 'release' containers for log_[signer,server]? HOT 5
- Cockroach tests are pinned to historic version HOT 4
- TX rollback error: sql: transaction has already been committed or rolled back HOT 2
- Document SCTs and the tradeoffs involved in using them
- FR: Ability to configure tree hashing algorithm, along with SHA3 support HOT 6
- Alternative construction to merkle trees
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
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.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from trillian.