Nov 01 12:41:16.777 INFO testing corpus-tools/graphANNIS against 1.30.0 for beta-1.31-1
Nov 01 12:41:16.778 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-1/worker-6/1.30.0:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/beta-1.31-1/1.30.0:/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 +1.30.0 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:17.259 INFO blam! 594408cec6ff953980c3ae2ca7b4917e9e8a1aa9a2bcd48b6f4acb4b41523733
Nov 01 12:41:17.262 INFO running `"docker" "start" "-a" "594408cec6ff953980c3ae2ca7b4917e9e8a1aa9a2bcd48b6f4acb4b41523733"`
Nov 01 12:41:18.310 INFO kablam! usermod: no changes
Nov 01 12:41:18.687 INFO kablam!    Compiling cfg-if v0.1.6
Nov 01 12:41:18.687 INFO kablam!    Compiling ucd-util v0.1.2
Nov 01 12:41:18.687 INFO kablam!    Compiling byte-tools v0.3.0
Nov 01 12:41:18.687 INFO kablam!    Compiling serde v1.0.80
Nov 01 12:41:18.687 INFO kablam!    Compiling utf8-ranges v1.0.2
Nov 01 12:41:18.687 INFO kablam!    Compiling byteorder v1.2.7
Nov 01 12:41:18.698 INFO kablam!    Compiling precomputed-hash v0.1.1
Nov 01 12:41:18.698 INFO kablam!    Compiling ordermap v0.3.5
Nov 01 12:41:19.212 INFO kablam!    Compiling opaque-debug v0.2.1
Nov 01 12:41:19.451 INFO kablam!    Compiling fixedbitset v0.1.9
Nov 01 12:41:19.542 INFO kablam!    Compiling bit-vec v0.5.0
Nov 01 12:41:21.203 INFO kablam!    Compiling lalrpop-util v0.16.1
Nov 01 12:41:23.227 INFO kablam!    Compiling unindent v0.1.3
Nov 01 12:41:25.099 INFO kablam!    Compiling diff v0.1.11
Nov 01 12:41:25.099 INFO kablam!    Compiling strum v0.11.0
Nov 01 12:41:25.099 INFO kablam!    Compiling graphannis-malloc_size_of v1.0.0
Nov 01 12:41:25.211 INFO kablam!    Compiling fs2 v0.4.3
Nov 01 12:41:25.736 INFO kablam!    Compiling sys-info v0.5.6
Nov 01 12:41:26.252 INFO kablam!    Compiling log v0.4.6
Nov 01 12:41:28.195 INFO kablam!    Compiling crossbeam-utils v0.2.2
Nov 01 12:41:28.219 INFO kablam!    Compiling block-padding v0.1.2
Nov 01 12:41:28.279 INFO kablam!    Compiling ascii-canvas v1.0.0
Nov 01 12:41:29.835 INFO kablam!    Compiling itertools v0.7.8
Nov 01 12:41:30.647 INFO kablam!    Compiling rustc-hash v1.0.1
Nov 01 12:41:30.663 INFO kablam!    Compiling bit-set v0.5.0
Nov 01 12:41:30.663 INFO kablam!    Compiling regex-syntax v0.6.2
Nov 01 12:41:30.739 INFO kablam!    Compiling heck v0.3.0
Nov 01 12:41:31.179 INFO kablam!    Compiling new_debug_unreachable v1.0.1
Nov 01 12:41:32.519 INFO kablam!    Compiling petgraph v0.4.13
Nov 01 12:41:33.127 INFO kablam!    Compiling ena v0.10.1
Nov 01 12:41:33.178 INFO kablam!    Compiling syn v0.13.11
Nov 01 12:41:33.327 INFO kablam!    Compiling memchr v2.1.1
Nov 01 12:41:33.611 INFO kablam!    Compiling generic-array v0.12.0
Nov 01 12:41:37.027 INFO kablam!    Compiling num-integer v0.1.39
Nov 01 12:41:37.080 INFO kablam!    Compiling num-complex v0.2.1
Nov 01 12:41:38.315 INFO kablam!    Compiling string_cache_codegen v0.4.2
Nov 01 12:41:42.428 INFO kablam!    Compiling thread_local v0.3.6
Nov 01 12:41:45.167 INFO kablam!    Compiling crossbeam-epoch v0.3.1
Nov 01 12:41:46.787 INFO kablam!    Compiling aho-corasick v0.6.9
Nov 01 12:41:47.003 INFO kablam!    Compiling csv-core v0.1.4
Nov 01 12:41:47.503 INFO kablam!    Compiling backtrace v0.3.9
Nov 01 12:41:54.733 INFO kablam!    Compiling block-buffer v0.7.0
Nov 01 12:41:54.955 INFO kablam!    Compiling digest v0.8.0
Nov 01 12:41:55.427 INFO kablam!    Compiling serde_derive v1.0.80
Nov 01 12:41:55.498 INFO kablam!    Compiling indoc-impl v0.2.8
Nov 01 12:41:55.535 INFO kablam!    Compiling strum_macros v0.11.0
Nov 01 12:41:55.639 INFO kablam!    Compiling num-bigint v0.2.0
Nov 01 12:41:56.591 INFO kablam!    Compiling num-iter v0.1.37
Nov 01 12:41:56.784 INFO kablam!    Compiling crossbeam-deque v0.2.0
Nov 01 12:41:58.299 INFO kablam!    Compiling error-chain v0.12.0
Nov 01 12:41:59.347 INFO kablam!    Compiling regex v1.0.5
Nov 01 12:42:05.215 INFO kablam!    Compiling string_cache v0.7.3
Nov 01 12:42:05.267 INFO kablam!    Compiling sha2 v0.8.0
Nov 01 12:42:08.695 INFO kablam!    Compiling rayon-core v1.4.1
Nov 01 12:42:20.267 INFO kablam!    Compiling num-rational v0.2.1
Nov 01 12:42:20.319 INFO kablam!    Compiling indoc v0.2.8
Nov 01 12:42:20.319 INFO kablam!    Compiling csv v1.0.2
Nov 01 12:42:20.511 INFO kablam!    Compiling multimap v0.4.0
Nov 01 12:42:20.623 INFO kablam!    Compiling bincode v1.0.1
Nov 01 12:42:25.139 INFO kablam!    Compiling rayon v1.0.2
Nov 01 12:42:25.183 INFO kablam!    Compiling boolean_expression v0.3.8
Nov 01 12:42:25.259 INFO kablam!    Compiling synstructure v0.8.1
Nov 01 12:42:25.923 INFO kablam!    Compiling num v0.2.0
Nov 01 12:42:29.712 INFO kablam!    Compiling docopt v1.0.2
Nov 01 12:42:42.477 INFO kablam!    Compiling lalrpop v0.16.1
Nov 01 12:42:42.771 INFO kablam!    Compiling graphannis-malloc_size_of_derive v1.0.0
Nov 01 12:43:38.811 INFO kablam!    Compiling graphannis v0.11.1 (/source)
Nov 01 12:44:35.820 INFO kablam!     Finished dev [unoptimized + debuginfo] target(s) in 3m 17s
Nov 01 12:44:35.841 INFO kablam! su: No module specific data is present
Nov 01 12:44:38.642 INFO running `"docker" "rm" "-f" "594408cec6ff953980c3ae2ca7b4917e9e8a1aa9a2bcd48b6f4acb4b41523733"`
Nov 01 12:44:38.920 INFO blam! 594408cec6ff953980c3ae2ca7b4917e9e8a1aa9a2bcd48b6f4acb4b41523733
Nov 01 12:44:38.929 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-1/worker-6/1.30.0:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/beta-1.31-1/1.30.0:/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 +1.30.0 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:39.333 INFO blam! 95f0f8cbd65bc8a3b3d7632e8b4aea06ce5485043fa0e04ab4a99a8220c3aebb
Nov 01 12:44:39.334 INFO running `"docker" "start" "-a" "95f0f8cbd65bc8a3b3d7632e8b4aea06ce5485043fa0e04ab4a99a8220c3aebb"`
Nov 01 12:44:40.590 INFO kablam! usermod: no changes
Nov 01 12:44:40.941 INFO kablam!    Compiling term v0.5.1
Nov 01 12:44:40.947 INFO kablam!    Compiling chrono v0.4.6
Nov 01 12:44:46.971 INFO kablam!    Compiling simplelog v0.5.3
Nov 01 12:44:48.361 INFO kablam!    Compiling graphannis v0.11.1 (/source)
Nov 01 12:45:43.857 INFO kablam!     Finished dev [unoptimized + debuginfo] target(s) in 1m 03s
Nov 01 12:45:43.879 INFO kablam! su: No module specific data is present
Nov 01 12:45:45.237 INFO running `"docker" "rm" "-f" "95f0f8cbd65bc8a3b3d7632e8b4aea06ce5485043fa0e04ab4a99a8220c3aebb"`
Nov 01 12:45:45.571 INFO blam! 95f0f8cbd65bc8a3b3d7632e8b4aea06ce5485043fa0e04ab4a99a8220c3aebb
Nov 01 12:45:45.580 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-1/worker-6/1.30.0:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/beta-1.31-1/1.30.0:/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 +1.30.0 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:46.061 INFO blam! eb266fa59d7413b10bbf92d43506cb2c175a3ee3f59f838b1047da1786349484
Nov 01 12:45:46.067 INFO running `"docker" "start" "-a" "eb266fa59d7413b10bbf92d43506cb2c175a3ee3f59f838b1047da1786349484"`
Nov 01 12:45:47.631 INFO kablam! usermod: no changes
Nov 01 12:45:47.975 INFO kablam!     Finished dev [unoptimized + debuginfo] target(s) in 0.31s
Nov 01 12:45:48.000 INFO kablam!      Running /target/debug/deps/graphannis-ad44b4b473340acf
Nov 01 12:45:48.005 INFO blam! 
Nov 01 12:45:48.005 INFO blam! running 10 tests
Nov 01 12:45:48.039 INFO blam! test annis::db::annostorage::tests::insert_same_anno ... ok
Nov 01 12:45:48.039 INFO blam! test annis::db::annostorage::symboltable::tests::insert_clear_insert_get ... ok
Nov 01 12:45:48.039 INFO blam! test annis::db::annostorage::symboltable::tests::insert_and_get ... ok
Nov 01 12:45:48.039 INFO blam! test annis::db::annostorage::tests::get_all_for_node ... ok
Nov 01 12:45:48.039 INFO blam! test annis::db::annostorage::tests::remove ... ok
Nov 01 12:45:48.040 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 1
Nov 01 12:45:48.041 INFO blam! test annis::db::tests::create_writeable_gs ... ok
Nov 01 12:45:48.041 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.041 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 2 to stack with new size 1
Nov 01 12:45:48.041 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 3 to stack with new size 2
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 1
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 3
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 4 to stack with new size 2
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 5 to stack with new size 3
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 3
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 5
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 6 to stack with new size 3
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 7 to stack with new size 4
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 5
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 7
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 7
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 6
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 7 from path
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 6
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 4
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 5 from path
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 6 from path
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 4
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 2
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 3 from path
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 4 from path
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.042 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 4 to stack with new size 1
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 2
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 4
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 4
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 3
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 4 to stack with new size 1
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 5 to stack with new size 2
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 3
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 5
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 6 to stack with new size 2
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 7 to stack with new size 3
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 5
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 7
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 7
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 6
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 7 from path
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 6
Nov 01 12:45:48.043 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 4
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 5 from path
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 6 from path
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 4
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 1
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 2 to stack with new size 1
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 3 to stack with new size 2
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 1
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 3
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 4 to stack with new size 2
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 5 to stack with new size 3
Nov 01 12:45:48.044 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 3
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 5
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 6 to stack with new size 3
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 7 to stack with new size 4
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 5
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 7
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 7
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 6
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 7 from path
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.045 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 6
Nov 01 12:45:48.046 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 4
Nov 01 12:45:48.046 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 5 from path
Nov 01 12:45:48.046 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 6 from path
Nov 01 12:45:48.046 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.046 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 4
Nov 01 12:45:48.046 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 2
Nov 01 12:45:48.046 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 3 from path
Nov 01 12:45:48.047 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:87] truncating 4 from path
Nov 01 12:45:48.047 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.047 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:119] adding 4 to stack with new size 1
Nov 01 12:45:48.047 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 2
Nov 01 12:45:48.047 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 4
Nov 01 12:45:48.047 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.047 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result true for node 4
Nov 01 12:45:48.047 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:82] enter node 7
Nov 01 12:45:48.048 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:102] removing from stack
Nov 01 12:45:48.048 INFO blam! 12:45:48 [TRACE] graphannis::annis::dfs: [src/annis/dfs.rs:123] enter_node finished with result false for node 7
Nov 01 12:45:48.055 INFO blam! test annis::db::graphstorage::adjacencylist::tests::simple_dag_find_all ... ok
Nov 01 12:45:48.059 INFO blam! 12:45:48 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  3139.75 MB
Nov 01 12:45:48.059 INFO blam! 12:45:48 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  3140.02 MB
Nov 01 12:45:48.059 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:671] applying updates
Nov 01 12:45:48.060 INFO blam! 12:45:48 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  3139.75 MB
Nov 01 12:45:48.060 INFO blam! 12:45:48 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  3139.75 MB
Nov 01 12:45:48.060 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "test", node_type: "node" }
Nov 01 12:45:48.060 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:682] memory updates completed
Nov 01 12:45:48.060 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:685] output location for persisting updates is "/tmp/annis_test.fBoBy1BnYjep/testcorpus"
Nov 01 12:45:48.060 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:694] writing WAL update log to "/tmp/annis_test.fBoBy1BnYjep/testcorpus/current/update_log.bin"
Nov 01 12:45:48.061 INFO blam! 12:45:48 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  3140.07 MB
Nov 01 12:45:48.061 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:671] applying updates
Nov 01 12:45:48.061 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "test", node_type: "node" }
Nov 01 12:45:48.061 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:682] memory updates completed
Nov 01 12:45:48.061 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:685] output location for persisting updates is "/tmp/annis_test.oPj7rtGx1YPu/testcorpus"
Nov 01 12:45:48.062 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:694] writing WAL update log to "/tmp/annis_test.oPj7rtGx1YPu/testcorpus/current/update_log.bin"
Nov 01 12:45:48.071 INFO blam! 12:45:48 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  3140.06 MB
Nov 01 12:45:48.071 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:671] applying updates
Nov 01 12:45:48.071 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "root", node_type: "corpus" }
Nov 01 12:45:48.072 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "root/doc1", node_type: "corpus" }
Nov 01 12:45:48.072 INFO blam! 12:45:48 [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:48.072 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "root/doc2", node_type: "corpus" }
Nov 01 12:45:48.072 INFO blam! 12:45:48 [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:48.072 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:682] memory updates completed
Nov 01 12:45:48.072 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:685] output location for persisting updates is "/tmp/annis_test.QTkUj4MNeWWJ/root"
Nov 01 12:45:48.073 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:694] writing WAL update log to "/tmp/annis_test.QTkUj4MNeWWJ/root/current/update_log.bin"
Nov 01 12:45:48.079 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:699] finished writing WAL update log
Nov 01 12:45:48.079 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:699] finished writing WAL update log
Nov 01 12:45:48.079 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:699] finished writing WAL update log
Nov 01 12:45:48.103 INFO blam! 12:45:48 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  3142.55 MB
Nov 01 12:45:48.103 INFO blam! 12:45:48 [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:48.103 INFO blam! 12:45:48 [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:48.106 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:661] Starting background thread to sync WAL updates
Nov 01 12:45:48.107 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:668] Finished background thread to sync WAL updates
Nov 01 12:45:48.111 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:661] Starting background thread to sync WAL updates
Nov 01 12:45:48.111 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:668] Finished background thread to sync WAL updates
Nov 01 12:45:48.111 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1539] Unlocked CorpusStorage lock file
Nov 01 12:45:48.111 INFO blam! 12:45:48 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  3141.88 MB
Nov 01 12:45:48.111 INFO blam! 12:45:48 [DEBUG] graphannis::annis::db::corpusstorage: Current cache size is 0.00 MB / max  3144.72 MB
Nov 01 12:45:48.111 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:671] applying updates
Nov 01 12:45:48.111 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:473] applying event AddNode { node_name: "test", node_type: "node" }
Nov 01 12:45:48.111 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:682] memory updates completed
Nov 01 12:45:48.111 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:685] output location for persisting updates is "/tmp/annis_test.fBoBy1BnYjep/testcorpus"
Nov 01 12:45:48.111 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:694] writing WAL update log to "/tmp/annis_test.fBoBy1BnYjep/testcorpus/current/update_log.bin"
Nov 01 12:45:48.111 INFO blam! 12:45:48 [TRACE] graphannis::annis::db: [src/annis/db/mod.rs:699] finished writing WAL update log
Nov 01 12:45:48.111 INFO blam! 12:45:48 [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:48.118 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:661] Starting background thread to sync WAL updates
Nov 01 12:45:48.119 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:668] Finished background thread to sync WAL updates
Nov 01 12:45:48.119 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1539] Unlocked CorpusStorage lock file
Nov 01 12:45:48.119 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:661] Starting background thread to sync WAL updates
Nov 01 12:45:48.131 INFO blam! test annis::db::corpusstorage::tests::load_cs_twice ... ok
Nov 01 12:45:48.359 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1539] Unlocked CorpusStorage lock file
Nov 01 12:45:48.359 INFO kablam! 12:45:48 [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:48.359 INFO kablam!    0:     0x559a91502955 - backtrace::backtrace::libunwind::trace::hba5052cf16a6608e
Nov 01 12:45:48.359 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/backtrace/libunwind.rs:53
Nov 01 12:45:48.359 INFO kablam!                          - backtrace::backtrace::trace::h7f53757600de709a
Nov 01 12:45:48.359 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/backtrace/mod.rs:42
Nov 01 12:45:48.359 INFO kablam!    1:     0x559a914fd0ee - backtrace::capture::Backtrace::new_unresolved::hc360bfe5b93d9931
Nov 01 12:45:48.359 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.9/src/capture.rs:88
Nov 01 12:45:48.359 INFO kablam!    2:     0x559a914fc26f - error_chain::backtrace::imp::InternalBacktrace::new::h9db116f61a9a2820
Nov 01 12:45:48.359 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/error-chain-0.12.0/src/backtrace.rs:56
Nov 01 12:45:48.359 INFO kablam!    3:     0x559a914fa37e - <error_chain::State as core::default::Default>::default::h6bc2e78e6b3ccf57
Nov 01 12:45:48.359 INFO kablam!                         at /cargo-home/registry/src/github.com-1ecc6299db9ec823/error-chain-0.12.0/src/lib.rs:666
Nov 01 12:45:48.359 INFO kablam!    4:     0x559a911b415b - graphannis::annis::errors::Error::from_kind::h23c589130db8cce4
Nov 01 12:45:48.359 INFO kablam!                         at /source/<::error_chain::error_chain::impl_error_chain_processed macros>:53
Nov 01 12:45:48.359 INFO kablam!    5:     0x559a911b448f - <graphannis::annis::errors::Error as core::convert::From<std::io::error::Error>>::from::h3a931e7fd78b18aa
Nov 01 12:45:48.359 INFO kablam!                         at src/annis/errors.rs:4
Nov 01 12:45:48.359 INFO kablam!    6:     0x559a90e52464 - graphannis::annis::db::Graph::background_sync_wal_updates::h0cdd5432b839d09a
Nov 01 12:45:48.359 INFO kablam!                         at src/annis/db/mod.rs:726
Nov 01 12:45:48.359 INFO kablam!    7:     0x559a90ea02a1 - graphannis::annis::db::corpusstorage::CorpusStorage::apply_update::{{closure}}::h5311bb99681fb3ac
Nov 01 12:45:48.359 INFO kablam!                         at src/annis/db/corpusstorage.rs:665
Nov 01 12:45:48.359 INFO kablam!    8:     0x559a91180bba - std::sys_common::backtrace::__rust_begin_short_backtrace::he7a17601cc8c8951
Nov 01 12:45:48.359 INFO kablam!                         at libstd/sys_common/backtrace.rs:136
Nov 01 12:45:48.359 INFO kablam!    9:     0x559a90e6e9ec - std::thread::Builder::spawn::{{closure}}::{{closure}}::h0991a5aaa25f626b
Nov 01 12:45:48.359 INFO kablam!                         at libstd/thread/mod.rs:409
Nov 01 12:45:48.359 INFO kablam!   10:     0x559a9103fc7c - <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h6922415f549274a8
Nov 01 12:45:48.359 INFO kablam!                         at libstd/panic.rs:313
Nov 01 12:45:48.359 INFO kablam!   11:     0x559a90e6ffbf - std::panicking::try::do_call::hbc3ac0d6f5a71d60
Nov 01 12:45:48.359 INFO kablam!                         at libstd/panicking.rs:310
Nov 01 12:45:48.359 INFO kablam!   12:     0x559a91549d89 - __rust_maybe_catch_panic
Nov 01 12:45:48.359 INFO kablam!                         at libpanic_unwind/lib.rs:103
Nov 01 12:45:48.359 INFO kablam!   13:     0x559a90e6f631 - std::panicking::try::h9ba4b725c612c052
Nov 01 12:45:48.359 INFO kablam!                         at libstd/panicking.rs:289
Nov 01 12:45:48.359 INFO kablam!   14:     0x559a9104107c - std::panic::catch_unwind::h853e487ca77c0d51
Nov 01 12:45:48.359 INFO kablam!                         at libstd/panic.rs:392
Nov 01 12:45:48.359 INFO kablam!   15:     0x559a90e6e80c - std::thread::Builder::spawn::{{closure}}::h56d1c3ef38223580
Nov 01 12:45:48.359 INFO kablam!                         at libstd/thread/mod.rs:408
Nov 01 12:45:48.359 INFO kablam!   16:     0x559a90e7a396 - <F as alloc::boxed::FnBox<A>>::call_box::h0eaabec13b8a0d43
Nov 01 12:45:48.359 INFO kablam!                         at liballoc/boxed.rs:646
Nov 01 12:45:48.359 INFO kablam!   17:     0x559a9153b46a - <alloc::boxed::Box<(dyn alloc::boxed::FnBox<A, Output=R> + 'a)> as core::ops::function::FnOnce<A>>::call_once::hd022a0500f5eee13
Nov 01 12:45:48.359 INFO kablam!                         at liballoc/boxed.rs:656
Nov 01 12:45:48.359 INFO kablam!                          - std::sys_common::thread::start_thread::hb77935aee02382da
Nov 01 12:45:48.359 INFO kablam!                         at libstd/sys_common/thread.rs:24
Nov 01 12:45:48.359 INFO kablam!   18:     0x559a9152abe5 - std::sys::unix::thread::Thread::new::thread_start::hd61f7429b3de1d75
Nov 01 12:45:48.359 INFO kablam!                         at libstd/sys/unix/thread.rs:90
Nov 01 12:45:48.359 INFO kablam!   19:     0x7f0ee8d8d6b9 - start_thread
Nov 01 12:45:48.359 INFO kablam!   20:     0x7f0ee88ad41c - clone
Nov 01 12:45:48.359 INFO kablam!   21:                0x0 - <unknown>) } })
Nov 01 12:45:48.359 INFO blam! 12:45:48 [TRACE] graphannis::annis::db::corpusstorage: [src/annis/db/corpusstorage.rs:1539] Unlocked CorpusStorage lock file
Nov 01 12:45:48.359 INFO blam! test annis::db::corpusstorage::tests::apply_update_add_nodes ... ok
Nov 01 12:45:48.359 INFO blam! test annis::db::corpusstorage::tests::delete ... ok
Nov 01 12:45:48.359 INFO blam! 
Nov 01 12:45:48.359 INFO blam! test result: ok. 10 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 01 12:45:48.359 INFO blam! 
Nov 01 12:45:48.367 INFO kablam!      Running /target/debug/deps/searchtest-6fb0899d3048eddd
Nov 01 12:45:48.367 INFO blam! 
Nov 01 12:45:48.367 INFO blam! running 1 test
Nov 01 12:45:48.367 INFO blam! test all_from_folder ... ignored
Nov 01 12:45:48.367 INFO blam! 
Nov 01 12:45:48.367 INFO blam! test result: ok. 0 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out
Nov 01 12:45:48.367 INFO blam! 
Nov 01 12:45:48.368 INFO kablam!      Running /target/debug/deps/searchtest_parallel-d83190e8a4a10ae6
Nov 01 12:45:48.369 INFO blam! 
Nov 01 12:45:48.369 INFO blam! running 1 test
Nov 01 12:45:48.369 INFO blam! test all_from_folder_parallel ... ignored
Nov 01 12:45:48.369 INFO blam! 
Nov 01 12:45:48.369 INFO blam! test result: ok. 0 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out
Nov 01 12:45:48.369 INFO blam! 
Nov 01 12:45:48.369 INFO kablam!    Doc-tests graphannis
Nov 01 12:45:53.732 INFO blam! 
Nov 01 12:45:53.732 INFO blam! running 1 test
Nov 01 12:46:03.709 INFO blam! test src/annis/util/mod.rs - annis::util::extract_node_path (line 35) ... ok
Nov 01 12:46:03.709 INFO blam! 
Nov 01 12:46:03.710 INFO blam! test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 01 12:46:03.710 INFO blam! 
Nov 01 12:46:03.741 INFO kablam! su: No module specific data is present
Nov 01 12:46:04.846 INFO running `"docker" "rm" "-f" "eb266fa59d7413b10bbf92d43506cb2c175a3ee3f59f838b1047da1786349484"`
Nov 01 12:46:05.183 INFO blam! eb266fa59d7413b10bbf92d43506cb2c175a3ee3f59f838b1047da1786349484
