Oct 11 19:46:34.019 INFO testing graphannis-0.9.0 against master#0e07c4281c343e9e15a0a8fca79538ad1a8eb513 for rustdoc-test-static-cling
Oct 11 19:46:34.020 INFO running: cargo +0e07c4281c343e9e15a0a8fca79538ad1a8eb513-alt build --frozen
Oct 11 19:46:34.025 INFO running `"docker" "create" "-v" "/mnt/big/crater/./work/local/test-source/worker-2/rustdoc-test-static-cling/master#0e07c4281c343e9e15a0a8fca79538ad1a8eb513:/source:ro,Z" "-v" "/mnt/big/crater/./work/local/target-dirs/rustdoc-test-static-cling/worker-2/master#0e07c4281c343e9e15a0a8fca79538ad1a8eb513:/target:rw,Z" "-v" "/mnt/big/crater/./work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/./work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "CMD=cargo +0e07c4281c343e9e15a0a8fca79538ad1a8eb513-alt build --frozen" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-m" "1536M" "--network" "none" "crater"`
Oct 11 19:46:34.480 INFO blam! 5f54b80938d2d6e6ecf1d5c831b9236af0926f923b7e01bb5acd56516654b253
Oct 11 19:46:34.482 INFO running `"docker" "start" "-a" "5f54b80938d2d6e6ecf1d5c831b9236af0926f923b7e01bb5acd56516654b253"`
Oct 11 19:46:35.157 INFO kablam! usermod: no changes
Oct 11 19:46:35.409 INFO kablam!    Compiling strum v0.10.0
Oct 11 19:46:35.409 INFO kablam!    Compiling graphannis-malloc_size_of v0.0.1
Oct 11 19:46:35.412 INFO kablam!    Compiling syn v0.13.11
Oct 11 19:46:35.412 INFO kablam!    Compiling multimap v0.4.0
Oct 11 19:46:35.412 INFO kablam!    Compiling bincode v1.0.1
Oct 11 19:46:35.428 INFO kablam!    Compiling csv v1.0.2
Oct 11 19:46:35.428 INFO kablam!    Compiling strum_macros v0.10.0
Oct 11 19:46:35.428 INFO kablam!    Compiling lalrpop-snap v0.15.2
Oct 11 19:47:04.387 INFO kablam!    Compiling synstructure v0.8.1
Oct 11 19:47:12.644 INFO kablam!    Compiling graphannis-malloc_size_of_derive v0.0.1
Oct 11 19:47:45.843 INFO kablam!    Compiling lalrpop v0.15.2
Oct 11 19:48:38.552 INFO kablam!    Compiling graphannis v0.9.0 (/source)
Oct 11 19:49:19.581 INFO kablam!     Finished dev [unoptimized + debuginfo] target(s) in 2m 44s
Oct 11 19:49:19.593 INFO kablam! su: No module specific data is present
Oct 11 19:49:20.004 INFO running `"docker" "rm" "-f" "5f54b80938d2d6e6ecf1d5c831b9236af0926f923b7e01bb5acd56516654b253"`
Oct 11 19:49:20.252 INFO blam! 5f54b80938d2d6e6ecf1d5c831b9236af0926f923b7e01bb5acd56516654b253
Oct 11 19:49:20.256 INFO running: cargo +0e07c4281c343e9e15a0a8fca79538ad1a8eb513-alt test --frozen --no-run
Oct 11 19:49:20.256 INFO running `"docker" "create" "-v" "/mnt/big/crater/./work/local/test-source/worker-2/rustdoc-test-static-cling/master#0e07c4281c343e9e15a0a8fca79538ad1a8eb513:/source:ro,Z" "-v" "/mnt/big/crater/./work/local/target-dirs/rustdoc-test-static-cling/worker-2/master#0e07c4281c343e9e15a0a8fca79538ad1a8eb513:/target:rw,Z" "-v" "/mnt/big/crater/./work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/./work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "CMD=cargo +0e07c4281c343e9e15a0a8fca79538ad1a8eb513-alt test --frozen --no-run" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-m" "1536M" "--network" "none" "crater"`
Oct 11 19:49:20.616 INFO blam! 34a14e1c2db9afe37acd10f88492ea8f013d192eec7a27dfaa03fe2b28679d95
Oct 11 19:49:20.616 INFO running `"docker" "start" "-a" "34a14e1c2db9afe37acd10f88492ea8f013d192eec7a27dfaa03fe2b28679d95"`
Oct 11 19:49:21.744 INFO kablam! usermod: no changes
Oct 11 19:49:22.112 INFO kablam!    Compiling chrono v0.4.6
Oct 11 19:49:25.969 INFO kablam!    Compiling simplelog v0.5.3
Oct 11 19:49:28.136 INFO kablam!    Compiling graphannis v0.9.0 (/source)
Oct 11 19:50:09.880 INFO kablam!     Finished dev [unoptimized + debuginfo] target(s) in 48.12s
Oct 11 19:50:09.897 INFO kablam! su: No module specific data is present
Oct 11 19:50:10.524 INFO running `"docker" "rm" "-f" "34a14e1c2db9afe37acd10f88492ea8f013d192eec7a27dfaa03fe2b28679d95"`
Oct 11 19:50:10.658 INFO blam! 34a14e1c2db9afe37acd10f88492ea8f013d192eec7a27dfaa03fe2b28679d95
Oct 11 19:50:10.665 INFO running: cargo +0e07c4281c343e9e15a0a8fca79538ad1a8eb513-alt test --frozen
Oct 11 19:50:10.666 INFO running `"docker" "create" "-v" "/mnt/big/crater/./work/local/test-source/worker-2/rustdoc-test-static-cling/master#0e07c4281c343e9e15a0a8fca79538ad1a8eb513:/source:ro,Z" "-v" "/mnt/big/crater/./work/local/target-dirs/rustdoc-test-static-cling/worker-2/master#0e07c4281c343e9e15a0a8fca79538ad1a8eb513:/target:rw,Z" "-v" "/mnt/big/crater/./work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/./work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "CMD=cargo +0e07c4281c343e9e15a0a8fca79538ad1a8eb513-alt test --frozen" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-m" "1536M" "--network" "none" "crater"`
Oct 11 19:50:11.137 INFO blam! c66374b854804318accab441ba3fdbf73136a56f3135788e3a1ae3c472ae89fd
Oct 11 19:50:11.142 INFO running `"docker" "start" "-a" "c66374b854804318accab441ba3fdbf73136a56f3135788e3a1ae3c472ae89fd"`
Oct 11 19:50:11.956 INFO kablam! usermod: no changes
Oct 11 19:50:12.255 INFO kablam!     Finished dev [unoptimized + debuginfo] target(s) in 0.28s
Oct 11 19:50:12.269 INFO kablam!      Running /target/debug/deps/graphannis-bfbc77dd412ddd3f
Oct 11 19:50:12.271 INFO blam! 
Oct 11 19:50:12.271 INFO blam! running 10 tests
Oct 11 19:50:12.274 INFO blam! 19:50:12 [INFO] Using cache with size 3308.02 MiB
Oct 11 19:50:12.274 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:515] applying updates
Oct 11 19:50:12.274 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:321] applying event AddNode { node_name: "test", node_type: "node" }
Oct 11 19:50:12.274 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:526] memory updates completed
Oct 11 19:50:12.274 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:529] output location for persisting updates is "/tmp/annis_test.BjBJ02BRJubp/testcorpus"
Oct 11 19:50:12.274 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:538] writing WAL update log to "/tmp/annis_test.BjBJ02BRJubp/testcorpus/current/update_log.bin"
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:543] finished writing WAL update log
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1387] Waiting for background thread to finish (1 worker(s) left)...
Oct 11 19:50:12.275 INFO blam! 19:50:12 [INFO] Using cache with size 3308.02 MiB
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 1
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 2 to stack with new size 1
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 3 to stack with new size 2
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result false for node 1
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 4 to stack with new size 2
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 5 to stack with new size 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 5
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 6 to stack with new size 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 7 to stack with new size 4
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 5
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 7
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 7
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 6
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 7 from path
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 6
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 4
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 5 from path
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 6 from path
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 4
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 2
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 3 from path
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 4 from path
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 4 to stack with new size 1
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 2
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 4
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! test annostorage::tests::insert_same_anno ... ok
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 4
Oct 11 19:50:12.275 INFO blam! test annostorage::tests::remove ... ok
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 4 to stack with new size 1
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 5 to stack with new size 2
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result false for node 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 5
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 6 to stack with new size 2
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 7 to stack with new size 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result false for node 5
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 7
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 7
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 6
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 7 from path
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 6
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 4
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 5 from path
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 6 from path
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result false for node 4
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 1
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 2 to stack with new size 1
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 3 to stack with new size 2
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result false for node 1
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 4 to stack with new size 2
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 5 to stack with new size 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result false for node 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 5
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 6 to stack with new size 3
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 7 to stack with new size 4
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 5
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 7
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 7
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 6
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 7 from path
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.275 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 6
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 4
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 5 from path
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 6 from path
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 4
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 2
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 3 from path
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:77] truncating 4 from path
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:109] adding 4 to stack with new size 1
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result false for node 2
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 4
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result true for node 4
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:72] enter node 7
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:92] removing from stack
Oct 11 19:50:12.276 INFO blam! 19:50:12 [TRACE] graphannis::dfs: [src/dfs.rs:113] enter_node finished with result false for node 7
Oct 11 19:50:12.285 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:515] applying updates
Oct 11 19:50:12.285 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:321] applying event AddNode { node_name: "test", node_type: "node" }
Oct 11 19:50:12.285 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:526] memory updates completed
Oct 11 19:50:12.285 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:529] output location for persisting updates is "/tmp/annis_test.iZXwH2JwmUuI/testcorpus"
Oct 11 19:50:12.285 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:538] writing WAL update log to "/tmp/annis_test.iZXwH2JwmUuI/testcorpus/current/update_log.bin"
Oct 11 19:50:12.285 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:543] finished writing WAL update log
Oct 11 19:50:12.285 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1387] Waiting for background thread to finish (1 worker(s) left)...
Oct 11 19:50:12.285 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1359] Starting background thread to sync WAL updates
Oct 11 19:50:12.285 INFO blam! test graphdb::tests::create_writeable_gs ... ok
Oct 11 19:50:12.285 INFO blam! test annostorage::tests::get_all_for_node ... ok
Oct 11 19:50:12.285 INFO blam! test stringstorage::tests::insert_and_get ... ok
Oct 11 19:50:12.285 INFO blam! test stringstorage::tests::insert_clear_insert_get ... ok
Oct 11 19:50:12.286 INFO blam! test stringstorage::tests::serialization ... ok
Oct 11 19:50:12.286 INFO blam! test graphstorage::adjacencylist::tests::simple_dag_find_all ... ok
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1359] Starting background thread to sync WAL updates
Oct 11 19:50:12.414 INFO kablam! 19:50:12 [ERROR] Can't sync changes in background thread: Error(IO(Os { code: 2, kind: NotFound, message: "No such file or directory" }), State { next_error: None, backtrace: InternalBacktrace { backtrace: Some(stack backtrace:
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1395] Unlocked CorpusStorage lock file
Oct 11 19:50:12.414 INFO kablam!    0:     0x5575431ca935 - backtrace::backtrace::libunwind::trace::hcfcf1fadd4f93900
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1366] Finished background thread to sync WAL updates
Oct 11 19:50:12.414 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/backtrace/libunwind.rs:53
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1395] Unlocked CorpusStorage lock file
Oct 11 19:50:12.414 INFO kablam!                          - backtrace::backtrace::trace::hf39fe23bdce9b3c2
Oct 11 19:50:12.414 INFO blam! 19:50:12 [INFO] Using cache with size 3299.56 MiB
Oct 11 19:50:12.414 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/backtrace/mod.rs:42
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:515] applying updates
Oct 11 19:50:12.414 INFO kablam!    1:     0x5575431c4f9e - backtrace::capture::Backtrace::new_unresolved::hc17f349eff464636
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:321] applying event AddNode { node_name: "test", node_type: "node" }
Oct 11 19:50:12.414 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/capture.rs:88
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:526] memory updates completed
Oct 11 19:50:12.414 INFO kablam!    2:     0x5575431c399a - error_chain::backtrace::imp::InternalBacktrace::new::hefdd390c82b680ca
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:529] output location for persisting updates is "/tmp/annis_test.BjBJ02BRJubp/testcorpus"
Oct 11 19:50:12.414 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/error-chain-0.12.0/src/backtrace.rs:56
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:538] writing WAL update log to "/tmp/annis_test.BjBJ02BRJubp/testcorpus/current/update_log.bin"
Oct 11 19:50:12.414 INFO kablam!    3:     0x5575431c1ece - <error_chain::State as core::default::Default>::default::hc371f6e644c01234
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::graphdb: [src/graphdb.rs:543] finished writing WAL update log
Oct 11 19:50:12.414 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/error-chain-0.12.0/src/lib.rs:666
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1387] Waiting for background thread to finish (1 worker(s) left)...
Oct 11 19:50:12.414 INFO kablam!    4:     0x5575430af63b - graphannis::errors::Error::from_kind::hc57de26111696c7d
Oct 11 19:50:12.414 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1359] Starting background thread to sync WAL updates
Oct 11 19:50:12.414 INFO kablam!                         at /source/<::error_chain::error_chain::impl_error_chain_processed macros>:53
Oct 11 19:50:12.414 INFO kablam!    5:     0x5575430af95f - <graphannis::errors::Error as core::convert::From<std::io::error::Error>>::from::hf4b7995ba0d1e727
Oct 11 19:50:12.414 INFO kablam!                         at src/errors.rs:5
Oct 11 19:50:12.414 INFO kablam!    6:     0x557543072194 - graphannis::graphdb::GraphDB::background_sync_wal_updates::h77fc975fcec1e332
Oct 11 19:50:12.414 INFO kablam!                         at src/graphdb.rs:570
Oct 11 19:50:12.414 INFO kablam!    7:     0x557542de4911 - graphannis::api::corpusstorage::CorpusStorage::apply_update::{{closure}}::ha42222fdf0cb5f5d
Oct 11 19:50:12.414 INFO kablam!                         at src/api/corpusstorage.rs:1363
Oct 11 19:50:12.414 INFO kablam!    8:     0x557542e01eca - std::sys_common::backtrace::__rust_begin_short_backtrace::h9a5182ec74e9626b
Oct 11 19:50:12.414 INFO kablam!                         at libstd/sys_common/backtrace.rs:136
Oct 11 19:50:12.414 INFO kablam!    9:     0x557542e70dac - std::thread::Builder::spawn::{{closure}}::{{closure}}::h8fad3a6aee82e535
Oct 11 19:50:12.414 INFO kablam!                         at libstd/thread/mod.rs:409
Oct 11 19:50:12.414 INFO kablam!   10:     0x557542e015bc - <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h33107ed132f40022
Oct 11 19:50:12.414 INFO kablam!                         at libstd/panic.rs:313
Oct 11 19:50:12.414 INFO kablam!   11:     0x557542e02a0f - std::panicking::try::do_call::hfb2018d379a2e9e4
Oct 11 19:50:12.414 INFO kablam!                         at libstd/panicking.rs:310
Oct 11 19:50:12.414 INFO kablam!   12:     0x557543210899 - __rust_maybe_catch_panic
Oct 11 19:50:12.414 INFO kablam!                         at libpanic_unwind/lib.rs:102
Oct 11 19:50:12.414 INFO kablam!   13:     0x557542e02931 - std::panicking::try::haaae5110072be91b
Oct 11 19:50:12.414 INFO kablam!                         at libstd/panicking.rs:289
Oct 11 19:50:12.414 INFO kablam!   14:     0x557542e028bc - std::panic::catch_unwind::h2839d438178549e3
Oct 11 19:50:12.414 INFO kablam!                         at libstd/panic.rs:392
Oct 11 19:50:12.414 INFO kablam!   15:     0x557542e70bc0 - std::thread::Builder::spawn::{{closure}}::hdd91d6567b66a33b
Oct 11 19:50:12.414 INFO kablam!                         at libstd/thread/mod.rs:408
Oct 11 19:50:12.414 INFO kablam!   16:     0x557542e83886 - <F as alloc::boxed::FnBox<A>>::call_box::h9b2977f7890dfd7c
Oct 11 19:50:12.414 INFO kablam!                         at liballoc/boxed.rs:672
Oct 11 19:50:12.414 INFO kablam!   17:     0x5575431fe74a - <alloc::boxed::Box<(dyn alloc::boxed::FnBox<A, Output=R> + 'a)> as core::ops::function::FnOnce<A>>::call_once::h2a88b48001a8d047
Oct 11 19:50:12.414 INFO kablam!                         at liballoc/boxed.rs:682
Oct 11 19:50:12.414 INFO kablam!                          - std::sys_common::thread::start_thread::h97c4c5d82028f6b1
Oct 11 19:50:12.414 INFO kablam!                         at libstd/sys_common/thread.rs:24
Oct 11 19:50:12.414 INFO kablam!   18:     0x5575431f2df5 - std::sys::unix::thread::Thread::new::thread_start::he7d65efc4dd16886
Oct 11 19:50:12.414 INFO kablam!                         at libstd/sys/unix/thread.rs:90
Oct 11 19:50:12.414 INFO kablam!   19:     0x7f4e048516b9 - start_thread
Oct 11 19:50:12.414 INFO kablam!   20:     0x7f4e0437141c - clone
Oct 11 19:50:12.414 INFO kablam!   21:                0x0 - <unknown>) } })
Oct 11 19:50:12.414 INFO blam! test api::corpusstorage::tests::delete ... ok
Oct 11 19:50:12.421 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1366] Finished background thread to sync WAL updates
Oct 11 19:50:12.421 INFO kablam!      Running /target/debug/deps/loadtest-278a8beb06c0dc34
Oct 11 19:50:12.421 INFO blam! 19:50:12 [TRACE] graphannis::api::corpusstorage: [src/api/corpusstorage.rs:1395] Unlocked CorpusStorage lock file
Oct 11 19:50:12.421 INFO blam! test api::corpusstorage::tests::load_cs_twice ... ok
Oct 11 19:50:12.421 INFO blam! 
Oct 11 19:50:12.421 INFO blam! test result: ok. 10 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Oct 11 19:50:12.421 INFO blam! 
Oct 11 19:50:12.421 INFO blam! 
Oct 11 19:50:12.421 INFO blam! running 7 tests
Oct 11 19:50:12.421 INFO blam! test node_annos ... ok
Oct 11 19:50:12.421 INFO blam! test parallel_index_join ... ok
Oct 11 19:50:12.424 INFO blam! test parallel_nested_loop_join ... ok
Oct 11 19:50:12.424 INFO kablam!      Running /target/debug/deps/searchtest-b15f58b09f217f3d
Oct 11 19:50:12.425 INFO blam! test count_annos ... ok
Oct 11 19:50:12.425 INFO blam! test nested_loop_join ... ok
Oct 11 19:50:12.425 INFO kablam!      Running /target/debug/deps/searchtest_parallel-dad3bfb3a069153d
Oct 11 19:50:12.425 INFO blam! test index_join ... ok
Oct 11 19:50:12.425 INFO blam! test edges ... ok
Oct 11 19:50:12.425 INFO blam! 
Oct 11 19:50:12.425 INFO blam! test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Oct 11 19:50:12.425 INFO blam! 
Oct 11 19:50:12.425 INFO blam! 
Oct 11 19:50:12.425 INFO blam! running 6 tests
Oct 11 19:50:12.425 INFO blam! test all_from_folder ... ignored
Oct 11 19:50:12.425 INFO blam! test count_gum ... ignored
Oct 11 19:50:12.425 INFO blam! test count_parlament ... ignored
Oct 11 19:50:12.425 INFO blam! test count_pcc2 ... ignored
Oct 11 19:50:12.425 INFO blam! test count_ridges ... ignored
Oct 11 19:50:12.426 INFO blam! test count_tiger ... ignored
Oct 11 19:50:12.426 INFO blam! 
Oct 11 19:50:12.426 INFO blam! test result: ok. 0 passed; 0 failed; 6 ignored; 0 measured; 0 filtered out
Oct 11 19:50:12.426 INFO blam! 
Oct 11 19:50:12.427 INFO blam! 
Oct 11 19:50:12.427 INFO blam! running 6 tests
Oct 11 19:50:12.431 INFO blam! test all_from_folder ... ignored
Oct 11 19:50:12.431 INFO kablam!    Doc-tests graphannis
Oct 11 19:50:12.431 INFO blam! test count_gum ... ignored
Oct 11 19:50:12.431 INFO blam! test count_parlament ... ignored
Oct 11 19:50:12.431 INFO blam! test count_pcc2 ... ignored
Oct 11 19:50:12.431 INFO blam! test count_ridges ... ignored
Oct 11 19:50:12.431 INFO blam! test count_tiger ... ignored
Oct 11 19:50:12.431 INFO blam! 
Oct 11 19:50:12.431 INFO blam! test result: ok. 0 passed; 0 failed; 6 ignored; 0 measured; 0 filtered out
Oct 11 19:50:12.431 INFO blam! 
Oct 11 19:50:21.004 INFO blam! 
Oct 11 19:50:21.004 INFO blam! running 1 test
Oct 11 19:50:35.404 INFO blam! test src/util/mod.rs - util::extract_node_path (line 75) ... ok
Oct 11 19:50:35.405 INFO blam! 
Oct 11 19:50:35.405 INFO blam! test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Oct 11 19:50:35.405 INFO blam! 
Oct 11 19:50:35.436 INFO kablam! su: No module specific data is present
Oct 11 19:50:36.238 INFO running `"docker" "rm" "-f" "c66374b854804318accab441ba3fdbf73136a56f3135788e3a1ae3c472ae89fd"`
Oct 11 19:50:36.376 INFO blam! c66374b854804318accab441ba3fdbf73136a56f3135788e3a1ae3c472ae89fd