Nov 01 12:41:11.044 INFO testing corpus-tools/graphANNIS against beta-2018-10-30 for beta-1.31-1
Nov 01 12:41:11.044 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-1/worker-0/beta-2018-10-30:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-0/beta-1.31-1/beta-2018-10-30:/source:ro,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" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +beta-2018-10-30 build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Nov 01 12:41:11.714 INFO blam! 2686de24578d36671acb3bd09b8b5b0bb6942077e7b18f9b1e8a5d314dce19b5
Nov 01 12:41:11.716 INFO running `"docker" "start" "-a" "2686de24578d36671acb3bd09b8b5b0bb6942077e7b18f9b1e8a5d314dce19b5"`
Nov 01 12:41:12.951 INFO kablam! usermod: no changes
Nov 01 12:41:13.293 INFO kablam!    Compiling serde v1.0.80
Nov 01 12:41:13.310 INFO kablam!    Compiling lalrpop-util v0.16.1
Nov 01 12:41:13.310 INFO kablam!    Compiling num-complex v0.2.1
Nov 01 12:41:13.311 INFO kablam!    Compiling graphannis-malloc_size_of v1.0.0
Nov 01 12:41:13.311 INFO kablam!    Compiling strum v0.11.0
Nov 01 12:41:13.319 INFO kablam!    Compiling crossbeam-utils v0.2.2
Nov 01 12:41:13.319 INFO kablam!    Compiling rustc-hash v1.0.1
Nov 01 12:41:13.320 INFO kablam!    Compiling sys-info v0.5.6
Nov 01 12:41:15.919 INFO kablam!    Compiling heck v0.3.0
Nov 01 12:41:15.932 INFO kablam!    Compiling ena v0.10.1
Nov 01 12:41:15.947 INFO kablam!    Compiling syn v0.13.11
Nov 01 12:41:16.031 INFO kablam!    Compiling string_cache_codegen v0.4.2
Nov 01 12:41:16.748 INFO kablam!    Compiling csv-core v0.1.4
Nov 01 12:41:16.815 INFO kablam!    Compiling block-buffer v0.7.0
Nov 01 12:41:17.028 INFO kablam!    Compiling num-bigint v0.2.0
Nov 01 12:41:18.557 INFO kablam!    Compiling num-iter v0.1.37
Nov 01 12:41:20.023 INFO kablam!    Compiling indoc-impl v0.2.8
Nov 01 12:41:21.159 INFO kablam!    Compiling crossbeam-epoch v0.3.1
Nov 01 12:41:22.367 INFO kablam!    Compiling sha2 v0.8.0
Nov 01 12:41:22.735 INFO kablam!    Compiling error-chain v0.12.0
Nov 01 12:41:30.208 INFO kablam!    Compiling strum_macros v0.11.0
Nov 01 12:41:30.252 INFO kablam!    Compiling crossbeam-deque v0.2.0
Nov 01 12:41:37.283 INFO kablam!    Compiling rayon-core v1.4.1
Nov 01 12:41:37.311 INFO kablam!    Compiling string_cache v0.7.3
Nov 01 12:41:37.467 INFO kablam!    Compiling num-rational v0.2.1
Nov 01 12:41:38.483 INFO kablam!    Compiling indoc v0.2.8
Nov 01 12:41:39.668 INFO kablam!    Compiling boolean_expression v0.3.8
Nov 01 12:41:44.645 INFO kablam!    Compiling rayon v1.0.2
Nov 01 12:41:44.655 INFO kablam!    Compiling num v0.2.0
Nov 01 12:42:02.287 INFO kablam!    Compiling docopt v1.0.2
Nov 01 12:42:02.287 INFO kablam!    Compiling csv v1.0.2
Nov 01 12:42:02.287 INFO kablam!    Compiling bincode v1.0.1
Nov 01 12:42:02.287 INFO kablam!    Compiling multimap v0.4.0
Nov 01 12:42:04.351 INFO kablam!    Compiling synstructure v0.8.1
Nov 01 12:42:10.446 INFO kablam!    Compiling lalrpop v0.16.1
Nov 01 12:42:12.789 INFO kablam!    Compiling graphannis-malloc_size_of_derive v1.0.0
Nov 01 12:43:02.318 INFO kablam!    Compiling graphannis v0.11.1 (/source)
Nov 01 12:43:58.171 INFO kablam!     Finished dev [unoptimized + debuginfo] target(s) in 2m 45s
Nov 01 12:43:58.191 INFO kablam! su: No module specific data is present
Nov 01 12:44:00.395 INFO running `"docker" "rm" "-f" "2686de24578d36671acb3bd09b8b5b0bb6942077e7b18f9b1e8a5d314dce19b5"`
Nov 01 12:44:00.779 INFO blam! 2686de24578d36671acb3bd09b8b5b0bb6942077e7b18f9b1e8a5d314dce19b5
Nov 01 12:44:00.783 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-1/worker-0/beta-2018-10-30:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-0/beta-1.31-1/beta-2018-10-30:/source:ro,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" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +beta-2018-10-30 test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Nov 01 12:44:01.346 INFO blam! 223c77a8e0af83afcaf2872c9ef93ebb579562d7a634c6979a317c74318b619c
Nov 01 12:44:01.347 INFO running `"docker" "start" "-a" "223c77a8e0af83afcaf2872c9ef93ebb579562d7a634c6979a317c74318b619c"`
Nov 01 12:44:03.095 INFO kablam! usermod: no changes
Nov 01 12:44:03.431 INFO kablam!    Compiling term v0.5.1
Nov 01 12:44:03.439 INFO kablam!    Compiling chrono v0.4.6
Nov 01 12:44:08.919 INFO kablam!    Compiling simplelog v0.5.3
Nov 01 12:44:10.564 INFO kablam!    Compiling graphannis v0.11.1 (/source)
Nov 01 12:45:04.679 INFO kablam!     Finished dev [unoptimized + debuginfo] target(s) in 1m 01s
Nov 01 12:45:04.703 INFO kablam! su: No module specific data is present
Nov 01 12:45:05.747 INFO running `"docker" "rm" "-f" "223c77a8e0af83afcaf2872c9ef93ebb579562d7a634c6979a317c74318b619c"`
Nov 01 12:45:06.071 INFO blam! 223c77a8e0af83afcaf2872c9ef93ebb579562d7a634c6979a317c74318b619c
Nov 01 12:45:06.087 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-1/worker-0/beta-2018-10-30:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-0/beta-1.31-1/beta-2018-10-30:/source:ro,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" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +beta-2018-10-30 test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Nov 01 12:45:06.629 INFO blam! e5aca20ded83a93af3e3a5631d86f30533d88c0fb20be5ec293bb9faa6d57d2a
Nov 01 12:45:06.631 INFO running `"docker" "start" "-a" "e5aca20ded83a93af3e3a5631d86f30533d88c0fb20be5ec293bb9faa6d57d2a"`
Nov 01 12:45:08.058 INFO kablam! usermod: no changes
Nov 01 12:45:08.405 INFO kablam!     Finished dev [unoptimized + debuginfo] target(s) in 0.31s
Nov 01 12:45:08.429 INFO kablam!      Running /target/debug/deps/graphannis-6bead42bed81eb25
Nov 01 12:45:08.443 INFO blam! 
Nov 01 12:45:08.443 INFO blam! running 10 tests
Nov 01 12:45:08.483 INFO blam! test annis::db::annostorage::tests::insert_same_anno ... ok
Nov 01 12:45:08.499 INFO blam! test annis::db::annostorage::symboltable::tests::insert_and_get ... ok
Nov 01 12:45:08.500 INFO blam! test annis::db::annostorage::symboltable::tests::insert_clear_insert_get ... ok
Nov 01 12:45:08.500 INFO blam! test annis::db::annostorage::tests::get_all_for_node ... ok
Nov 01 12:45:08.503 INFO blam! test annis::db::annostorage::tests::remove ... ok
Nov 01 12:45:08.508 INFO blam! 12:45:08 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  2988.46 MB
Nov 01 12:45:08.509 INFO blam! 12:45:08 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  2988.40 MB
Nov 01 12:45:08.509 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:671] applying updates
Nov 01 12:45:08.510 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "root", node_type: "corpus" }
Nov 01 12:45:08.510 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "root/doc1", node_type: "corpus" }
Nov 01 12:45:08.510 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "root/doc1#MyToken", node_type: "node" }
Nov 01 12:45:08.511 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "root/doc2", node_type: "corpus" }
Nov 01 12:45:08.512 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "root/doc2#MyToken", node_type: "node" }
Nov 01 12:45:08.512 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:682] memory updates completed
Nov 01 12:45:08.512 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:685] output location for persisting updates is "/tmp/annis_test.d4FjHoXKPZT8/root"
Nov 01 12:45:08.512 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:694] writing WAL update log to "/tmp/annis_test.d4FjHoXKPZT8/root/current/update_log.bin"
Nov 01 12:45:08.512 INFO blam! 12:45:08 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  2988.35 MB
Nov 01 12:45:08.527 INFO blam! 12:45:08 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  2987.39 MB
Nov 01 12:45:08.528 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:671] applying updates
Nov 01 12:45:08.528 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "test", node_type: "node" }
Nov 01 12:45:08.528 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:682] memory updates completed
Nov 01 12:45:08.528 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:685] output location for persisting updates is "/tmp/annis_test.wiWwiJz7LO4P/testcorpus"
Nov 01 12:45:08.528 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:694] writing WAL update log to "/tmp/annis_test.wiWwiJz7LO4P/testcorpus/current/update_log.bin"
Nov 01 12:45:08.543 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 1
Nov 01 12:45:08.544 INFO blam! test annis::db::tests::create_writeable_gs ... ok
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:699] finished writing WAL update log
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:699] finished writing WAL update log
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 2 to stack with new size 1
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 3 to stack with new size 2
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 1
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 3
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 4 to stack with new size 2
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 5 to stack with new size 3
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 3
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 5
Nov 01 12:45:08.544 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 6 to stack with new size 3
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 7 to stack with new size 4
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 5
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 7
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 7
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 6
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 7 from path
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 6
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 4
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 5 from path
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 6 from path
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 4
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 2
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 3 from path
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 4 from path
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 4 to stack with new size 1
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 2
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 4
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 4
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 3
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 4 to stack with new size 1
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 5 to stack with new size 2
Nov 01 12:45:08.547 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 3
Nov 01 12:45:08.548 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 5
Nov 01 12:45:08.548 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.548 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 6 to stack with new size 2
Nov 01 12:45:08.548 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 7 to stack with new size 3
Nov 01 12:45:08.548 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 5
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 7
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 7
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 6
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 7 from path
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 6
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 4
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 5 from path
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 6 from path
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 4
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 1
Nov 01 12:45:08.559 INFO blam! 12:45:08 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  2986.76 MB
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 2 to stack with new size 1
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 3 to stack with new size 2
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 1
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 3
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 4 to stack with new size 2
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 5 to stack with new size 3
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 3
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 5
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 6 to stack with new size 3
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 7 to stack with new size 4
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 5
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 7
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 7
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 6
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 7 from path
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 6
Nov 01 12:45:08.559 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 4
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 5 from path
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 6 from path
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 4
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 2
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 3 from path
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 4 from path
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 4 to stack with new size 1
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 2
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 4
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 4
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 7
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:08.562 INFO blam! 12:45:08 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 7
Nov 01 12:45:08.562 INFO blam! test annis::db::graphstorage::adjacencylist::tests::simple_dag_find_all ... ok
Nov 01 12:45:08.563 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1528] Waiting for background thread to finish (1 worker(s) left)...
Nov 01 12:45:08.588 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:661] Starting background thread to sync WAL updates
Nov 01 12:45:08.591 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:661] Starting background thread to sync WAL updates
Nov 01 12:45:08.591 INFO blam! 12:45:08 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  2984.88 MB
Nov 01 12:45:08.591 INFO blam! 12:45:08 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  2984.53 MB
Nov 01 12:45:08.595 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:671] applying updates
Nov 01 12:45:08.595 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "test", node_type: "node" }
Nov 01 12:45:08.595 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:682] memory updates completed
Nov 01 12:45:08.595 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:685] output location for persisting updates is "/tmp/annis_test.9V0eoilSFdLF/testcorpus"
Nov 01 12:45:08.595 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:694] writing WAL update log to "/tmp/annis_test.9V0eoilSFdLF/testcorpus/current/update_log.bin"
Nov 01 12:45:08.595 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:699] finished writing WAL update log
Nov 01 12:45:08.595 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1528] Waiting for background thread to finish (1 worker(s) left)...
Nov 01 12:45:08.902 INFO kablam! 12:45:08 [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:
Nov 01 12:45:08.902 INFO kablam!    0:     0x55dd508544d6 - backtrace::backtrace::libunwind::trace::hc561409b688814b6
Nov 01 12:45:08.902 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/backtrace/libunwind.rs:53
Nov 01 12:45:08.902 INFO kablam!                          - backtrace::backtrace::trace::h8dba8a3e72707af9
Nov 01 12:45:08.902 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/backtrace/mod.rs:42
Nov 01 12:45:08.902 INFO kablam!    1:     0x55dd5084eb93 - backtrace::capture::Backtrace::new_unresolved::h5b95b42aa0b46afa
Nov 01 12:45:08.902 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/capture.rs:88
Nov 01 12:45:08.902 INFO kablam!    2:     0x55dd5084d666 - error_chain::backtrace::imp::InternalBacktrace::new::h57017c541f65f711
Nov 01 12:45:08.902 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/error-chain-0.12.0/src/backtrace.rs:56
Nov 01 12:45:08.902 INFO kablam!    3:     0x55dd5084bd72 - <error_chain::State as core::default::Default>::default::hccb7667b59ce0e5a
Nov 01 12:45:08.902 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/error-chain-0.12.0/src/lib.rs:666
Nov 01 12:45:08.902 INFO kablam!    4:     0x55dd5053259f - graphannis::annis::errors::Error::from_kind::hd9756116a0de7845
Nov 01 12:45:08.902 INFO kablam!                         at /source/<::error_chain::error_chain::impl_error_chain_processed macros>:53
Nov 01 12:45:08.902 INFO kablam!    5:     0x55dd505328df - <graphannis::annis::errors::Error as core::convert::From<std::io::error::Error>>::from::h1dd4a9f2725f5565
Nov 01 12:45:08.902 INFO kablam!                         at src/annis/errors.rs:4
Nov 01 12:45:08.902 INFO kablam!    6:     0x55dd5019e625 - graphannis::annis::db::Graph::background_sync_wal_updates::h8e453a58ff0c179a
Nov 01 12:45:08.902 INFO kablam!                         at src/annis/db/mod.rs:726
Nov 01 12:45:08.903 INFO kablam!    7:     0x55dd503bbe85 - graphannis::annis::db::corpusstorage::CorpusStorage::apply_update::{{closure}}::h0bc5a1304c0db3db
Nov 01 12:45:08.903 INFO kablam!                         at src/annis/db/corpusstorage.rs:665
Nov 01 12:45:08.903 INFO kablam!    8:     0x55dd504ce9ba - std::sys_common::backtrace::__rust_begin_short_backtrace::h15ed9c89522e3db4
Nov 01 12:45:08.903 INFO kablam!                         at libstd/sys_common/backtrace.rs:136
Nov 01 12:45:08.911 INFO kablam!    9:     0x55dd501c7cbc - std::thread::Builder::spawn::{{closure}}::{{closure}}::h47abfb55d4ec1165
Nov 01 12:45:08.911 INFO kablam!                         at libstd/thread/mod.rs:409
Nov 01 12:45:08.911 INFO kablam!   10:     0x55dd501afe1c - <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h91a966a07d030729
Nov 01 12:45:08.911 INFO kablam!                         at libstd/panic.rs:313
Nov 01 12:45:08.911 INFO kablam!   11:     0x55dd501c91af - std::panicking::try::do_call::ha7ac93819de4b827
Nov 01 12:45:08.912 INFO kablam!                         at libstd/panicking.rs:310
Nov 01 12:45:08.912 INFO kablam!   12:     0x55dd5089b8d9 - __rust_maybe_catch_panic
Nov 01 12:45:08.912 INFO kablam!                         at libpanic_unwind/lib.rs:102
Nov 01 12:45:08.913 INFO kablam!   13:     0x55dd501c8a12 - std::panicking::try::hb45c3df3bee8f029
Nov 01 12:45:08.913 INFO kablam!                         at libstd/panicking.rs:289
Nov 01 12:45:08.913 INFO kablam!   14:     0x55dd501c6e7c - std::panic::catch_unwind::h2c66945f8fe69f08
Nov 01 12:45:08.914 INFO kablam!                         at libstd/panic.rs:392
Nov 01 12:45:08.915 INFO kablam!   15:     0x55dd501c7ac0 - std::thread::Builder::spawn::{{closure}}::hebe6abf5afe4ca36
Nov 01 12:45:08.915 INFO kablam!                         at libstd/thread/mod.rs:408
Nov 01 12:45:08.917 INFO kablam!   16:     0x55dd501d9ec6 - <F as alloc::boxed::FnBox<A>>::call_box::h289909e2d854de68
Nov 01 12:45:08.917 INFO kablam!                         at liballoc/boxed.rs:672
Nov 01 12:45:08.920 INFO kablam!   17:     0x55dd5088905d - <alloc::boxed::Box<(dyn alloc::boxed::FnBox<A, Output=R> + 'a)> as core::ops::function::FnOnce<A>>::call_once::h2e69ee95a52cd9a2
Nov 01 12:45:08.920 INFO kablam!                         at liballoc/boxed.rs:682
Nov 01 12:45:08.921 INFO kablam!                          - std::sys_common::thread::start_thread::had0c80d121669d29
Nov 01 12:45:08.921 INFO kablam!                         at libstd/sys_common/thread.rs:24
Nov 01 12:45:08.922 INFO kablam!   18:     0x55dd5087d445 - std::sys::unix::thread::Thread::new::thread_start::h4a5b66a70d76f47f
Nov 01 12:45:08.922 INFO kablam!                         at libstd/sys/unix/thread.rs:90
Nov 01 12:45:08.922 INFO kablam!   19:     0x7f9ea9b826b9 - start_thread
Nov 01 12:45:08.922 INFO kablam!   20:     0x7f9ea96a241c - clone
Nov 01 12:45:08.922 INFO kablam!   21:                0x0 - <unknown>) } })
Nov 01 12:45:08.922 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:661] Starting background thread to sync WAL updates
Nov 01 12:45:08.922 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:668] Finished background thread to sync WAL updates
Nov 01 12:45:08.922 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1528] Waiting for background thread to finish (1 worker(s) left)...
Nov 01 12:45:08.923 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1539] Unlocked CorpusStorage lock file
Nov 01 12:45:08.923 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1539] Unlocked CorpusStorage lock file
Nov 01 12:45:08.923 INFO blam! test annis::db::corpusstorage::tests::apply_update_add_nodes ... ok
Nov 01 12:45:08.923 INFO blam! test annis::db::corpusstorage::tests::delete ... ok
Nov 01 12:45:08.923 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:668] Finished background thread to sync WAL updates
Nov 01 12:45:08.923 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1539] Unlocked CorpusStorage lock file
Nov 01 12:45:08.924 INFO blam! 12:45:08 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  2965.49 MB
Nov 01 12:45:08.925 INFO blam! 12:45:08 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  2965.49 MB
Nov 01 12:45:08.925 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:671] applying updates
Nov 01 12:45:08.925 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "test", node_type: "node" }
Nov 01 12:45:08.925 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:682] memory updates completed
Nov 01 12:45:08.925 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:685] output location for persisting updates is "/tmp/annis_test.9V0eoilSFdLF/testcorpus"
Nov 01 12:45:08.925 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:694] writing WAL update log to "/tmp/annis_test.9V0eoilSFdLF/testcorpus/current/update_log.bin"
Nov 01 12:45:08.925 INFO blam! 12:45:08 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:699] finished writing WAL update log
Nov 01 12:45:08.925 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1528] Waiting for background thread to finish (1 worker(s) left)...
Nov 01 12:45:08.925 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:661] Starting background thread to sync WAL updates
Nov 01 12:45:08.926 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:668] Finished background thread to sync WAL updates
Nov 01 12:45:08.931 INFO blam! 12:45:08 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1539] Unlocked CorpusStorage lock file
Nov 01 12:45:08.931 INFO blam! test annis::db::corpusstorage::tests::load_cs_twice ... ok
Nov 01 12:45:08.931 INFO blam! 
Nov 01 12:45:08.931 INFO blam! test result: ok. 10 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 01 12:45:08.931 INFO blam! 
Nov 01 12:45:08.936 INFO kablam!      Running /target/debug/deps/searchtest-103d065f5164b413
Nov 01 12:45:08.938 INFO blam! 
Nov 01 12:45:08.938 INFO blam! running 1 test
Nov 01 12:45:08.938 INFO blam! test all_from_folder ... ignored
Nov 01 12:45:08.938 INFO blam! 
Nov 01 12:45:08.938 INFO blam! test result: ok. 0 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out
Nov 01 12:45:08.938 INFO blam! 
Nov 01 12:45:08.943 INFO kablam!      Running /target/debug/deps/searchtest_parallel-e13cba85d8672630
Nov 01 12:45:08.949 INFO blam! 
Nov 01 12:45:08.949 INFO blam! running 1 test
Nov 01 12:45:08.949 INFO blam! test all_from_folder_parallel ... ignored
Nov 01 12:45:08.949 INFO blam! 
Nov 01 12:45:08.949 INFO blam! test result: ok. 0 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out
Nov 01 12:45:08.949 INFO blam! 
Nov 01 12:45:08.955 INFO kablam!    Doc-tests graphannis
Nov 01 12:45:13.396 INFO blam! 
Nov 01 12:45:13.396 INFO blam! running 1 test
Nov 01 12:45:22.339 INFO blam! test src/annis/util/mod.rs - annis::util::extract_node_path (line 35) ... ok
Nov 01 12:45:22.340 INFO blam! 
Nov 01 12:45:22.340 INFO blam! test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 01 12:45:22.340 INFO blam! 
Nov 01 12:45:22.411 INFO kablam! su: No module specific data is present
Nov 01 12:45:24.275 INFO running `"docker" "rm" "-f" "e5aca20ded83a93af3e3a5631d86f30533d88c0fb20be5ec293bb9faa6d57d2a"`
Nov 01 12:45:24.635 INFO blam! e5aca20ded83a93af3e3a5631d86f30533d88c0fb20be5ec293bb9faa6d57d2a
