Dec 14 02:38:06.703 INFO testing apoloval/simproc against master#bd47d6825bf4090517549d33cfef10d3300b4a75 for pr-56550
Dec 14 02:38:06.703 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-4/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-alt build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 14 02:38:07.167 INFO [stdout] d46bf2454562115c9a52526e7d1d6c6133b55f0f13cd7dca70a2dba8bba4d1fb
Dec 14 02:38:07.169 INFO running `"docker" "start" "-a" "d46bf2454562115c9a52526e7d1d6c6133b55f0f13cd7dca70a2dba8bba4d1fb"`
Dec 14 02:38:09.279 INFO [stderr] usermod: no changes
Dec 14 02:38:09.453 INFO [stderr]    Compiling proc-macro2 v0.3.5
Dec 14 02:38:12.521 INFO [stderr]    Compiling quote v0.5.1
Dec 14 02:38:13.478 INFO [stderr]    Compiling syn v0.13.1
Dec 14 02:38:22.057 INFO [stderr]    Compiling serde_derive_internals v0.23.0
Dec 14 02:38:26.324 INFO [stderr]    Compiling serde_derive v1.0.37
Dec 14 02:38:37.065 INFO [stderr]    Compiling docopt v0.8.3
Dec 14 02:38:44.685 INFO [stderr]    Compiling simproc v0.1.0 (/source)
Dec 14 02:38:56.740 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 47.44s
Dec 14 02:38:56.754 INFO [stderr] su: No module specific data is present
Dec 14 02:39:01.909 INFO running `"docker" "inspect" "d46bf2454562115c9a52526e7d1d6c6133b55f0f13cd7dca70a2dba8bba4d1fb"`
Dec 14 02:39:02.137 INFO running `"docker" "rm" "-f" "d46bf2454562115c9a52526e7d1d6c6133b55f0f13cd7dca70a2dba8bba4d1fb"`
Dec 14 02:39:02.427 INFO [stdout] d46bf2454562115c9a52526e7d1d6c6133b55f0f13cd7dca70a2dba8bba4d1fb
Dec 14 02:39:02.430 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-4/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-alt test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 14 02:39:02.830 INFO [stdout] 2a9f6aaaad301e83b9bba9d212b3fec9f5b37487173e719f1776a003ba813b91
Dec 14 02:39:02.832 INFO running `"docker" "start" "-a" "2a9f6aaaad301e83b9bba9d212b3fec9f5b37487173e719f1776a003ba813b91"`
Dec 14 02:39:04.206 INFO [stderr] usermod: no changes
Dec 14 02:39:04.347 INFO [stderr]    Compiling env_logger v0.3.5
Dec 14 02:39:05.737 INFO [stderr]    Compiling quickcheck v0.2.27
Dec 14 02:39:08.858 INFO [stderr]    Compiling simproc v0.1.0 (/source)
Dec 14 02:39:18.927 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 14.67s
Dec 14 02:39:18.935 INFO [stderr] su: No module specific data is present
Dec 14 02:39:19.536 INFO running `"docker" "inspect" "2a9f6aaaad301e83b9bba9d212b3fec9f5b37487173e719f1776a003ba813b91"`
Dec 14 02:39:19.899 INFO running `"docker" "rm" "-f" "2a9f6aaaad301e83b9bba9d212b3fec9f5b37487173e719f1776a003ba813b91"`
Dec 14 02:39:20.096 INFO [stdout] 2a9f6aaaad301e83b9bba9d212b3fec9f5b37487173e719f1776a003ba813b91
Dec 14 02:39:20.101 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-4/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-alt test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 14 02:39:20.634 INFO [stdout] aca7447b76b9ceb66ead9bfa1986c5f23adafd4e7751d8412211dca121eff2b1
Dec 14 02:39:20.636 INFO running `"docker" "start" "-a" "aca7447b76b9ceb66ead9bfa1986c5f23adafd4e7751d8412211dca121eff2b1"`
Dec 14 02:39:21.585 INFO [stderr] usermod: no changes
Dec 14 02:39:21.699 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.09s
Dec 14 02:39:21.710 INFO [stderr]      Running /target/debug/deps/simproc-f78727ea28e2804a
Dec 14 02:39:21.712 INFO [stdout] 
Dec 14 02:39:21.713 INFO [stdout] running 231 tests
Dec 14 02:39:21.723 INFO [stdout] test cpu::clock::test::should_compute_cycles ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_compute_cycles_after_exec_sub ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_compute_cycles_after_exec_add ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::cpu::test::should_step_over ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::cpu::test::should_step_interpreting_invalid_opcode_as_nop ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_compute_cycles_after_exec_ld ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_compute_cycles_after_exec_st ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_compute_cycles_after_exec_mov ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_add_ignoring_carry ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_adc ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_add ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_adc_honoring_carry ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_di ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_decw ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_addi ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_com ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_dec ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_and ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_asr ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_ei ... ok
Dec 14 02:39:21.723 INFO [stdout] test cpu::exec::test::should_exec_call ... ok
Dec 14 02:39:21.731 INFO [stdout] test cpu::exec::test::should_exec_ijmp ... ok
Dec 14 02:39:21.731 INFO [stdout] test cpu::exec::test::should_exec_halt ... ok
Dec 14 02:39:21.731 INFO [stdout] test cpu::exec::test::should_exec_inc ... ok
Dec 14 02:39:21.731 INFO [stdout] test cpu::exec::test::should_exec_incw ... ok
Dec 14 02:39:21.731 INFO [stdout] test cpu::exec::test::should_exec_jcc ... ok
Dec 14 02:39:21.743 INFO [stdout] test cpu::exec::test::should_exec_jcs ... ok
Dec 14 02:39:21.743 INFO [stdout] test cpu::exec::test::should_exec_jmp ... ok
Dec 14 02:39:21.743 INFO [stdout] test cpu::exec::test::should_exec_jn ... ok
Dec 14 02:39:21.743 INFO [stdout] test cpu::exec::test::should_exec_jnz ... ok
Dec 14 02:39:21.743 INFO [stdout] test cpu::exec::test::should_exec_jp ... ok
Dec 14 02:39:21.743 INFO [stdout] test cpu::exec::test::should_exec_icall ... ok
Dec 14 02:39:21.743 INFO [stdout] test cpu::exec::test::should_exec_in ... ok
Dec 14 02:39:21.747 INFO [stdout] test cpu::exec::test::should_exec_ldsp ... ok
Dec 14 02:39:21.747 INFO [stdout] test cpu::exec::test::should_exec_ldi ... ok
Dec 14 02:39:21.747 INFO [stdout] test cpu::exec::test::should_exec_lsr ... ok
Dec 14 02:39:21.751 INFO [stdout] test cpu::exec::test::should_exec_lsl ... ok
Dec 14 02:39:21.751 INFO [stdout] test cpu::exec::test::should_exec_ldw ... ok
Dec 14 02:39:21.751 INFO [stdout] test cpu::exec::test::should_exec_ld ... ok
Dec 14 02:39:21.755 INFO [stdout] test cpu::exec::test::should_exec_jz ... ok
Dec 14 02:39:21.755 INFO [stdout] test cpu::exec::test::should_exec_jvs ... ok
Dec 14 02:39:21.755 INFO [stdout] test cpu::exec::test::should_exec_ldd ... ok
Dec 14 02:39:21.755 INFO [stdout] test cpu::exec::test::should_exec_neg ... ok
Dec 14 02:39:21.755 INFO [stdout] test cpu::exec::test::should_exec_jvc ... ok
Dec 14 02:39:21.755 INFO [stdout] test cpu::exec::test::should_exec_nop ... ok
Dec 14 02:39:21.755 INFO [stdout] test cpu::exec::test::should_exec_mov ... ok
Dec 14 02:39:21.759 INFO [stdout] test cpu::exec::test::should_exec_rjmp ... ok
Dec 14 02:39:21.759 INFO [stdout] test cpu::exec::test::should_exec_or ... ok
Dec 14 02:39:21.759 INFO [stdout] test cpu::exec::test::should_exec_out ... ok
Dec 14 02:39:21.759 INFO [stdout] test cpu::exec::test::should_exec_push ... ok
Dec 14 02:39:21.759 INFO [stdout] test cpu::exec::test::should_exec_rcall ... ok
Dec 14 02:39:21.759 INFO [stdout] test cpu::exec::test::should_exec_ret ... ok
Dec 14 02:39:21.759 INFO [stdout] test cpu::exec::test::should_exec_st ... ok
Dec 14 02:39:21.769 INFO [stdout] test cpu::exec::test::should_exec_sbc_honoring_carry ... ok
Dec 14 02:39:21.769 INFO [stdout] test cpu::exec::test::should_exec_sbc ... ok
Dec 14 02:39:21.769 INFO [stdout] test cpu::exec::test::should_exec_reti ... ok
Dec 14 02:39:21.769 INFO [stdout] test cpu::exec::test::should_exec_pop ... ok
Dec 14 02:39:21.769 INFO [stdout] test cpu::exec::test::should_exec_std ... ok
Dec 14 02:39:21.769 INFO [stdout] test cpu::exec::test::should_exec_sub ... ok
Dec 14 02:39:21.769 INFO [stdout] test cpu::exec::test::should_exec_sub_ignoring_carry ... ok
Dec 14 02:39:21.769 INFO [stdout] test cpu::exec::test::should_update_carry_after_exec_sub ... ok
Dec 14 02:39:21.770 INFO [stdout] test cpu::exec::test::should_exec_xor ... ok
Dec 14 02:39:21.770 INFO [stdout] test cpu::exec::test::should_update_carry_after_exec_add ... ok
Dec 14 02:39:21.770 INFO [stdout] test cpu::exec::test::should_update_carry_after_exec_asr ... ok
Dec 14 02:39:21.770 INFO [stdout] test cpu::exec::test::should_update_carry_after_exec_lsl ... ok
Dec 14 02:39:21.770 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_add ... ok
Dec 14 02:39:21.770 INFO [stdout] test cpu::exec::test::should_update_carry_after_exec_subi ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_addi ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_and ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_asr ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_com ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_dec ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_decw ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_inc ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_incw ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_lsl ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_xor ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_subi ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_sub ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_or ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_neg_after_exec_neg ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_exec_subi ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_carry_after_exec_addi ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_carry_after_exec_lsr ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_add ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_addi ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_asr ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_dec ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_decw ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_inc ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_incw ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_lsl ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_lsr ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_sub ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_overflow_after_exec_subi ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_pc_after_exec_add ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_pc_after_exec_and ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_pc_after_exec_ld ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_pc_after_exec_mov ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_pc_after_exec_or ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_pc_after_exec_st ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_pc_after_exec_sub ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_pc_after_exec_xor ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_add ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_addi ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_and ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_asr ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_com ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_dec ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_decw ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_inc ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_incw ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_lsl ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_lsr ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_neg ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_or ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_sub ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_subi ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::exec::test::should_update_zero_after_exec_xor ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::io::test::should_read_from_attached ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::io::test::should_read_zero_on_unattached ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::io::test::should_write_to_attached ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::reg::test::should_bind_aregs_to_dataregs ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::reg::test::should_bind_dataregs_to_aregs ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::reg::test::should_get_areg ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::reg::test::should_get_reg ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::reg::test::should_set_areg ... ok
Dec 14 02:39:21.776 INFO [stdout] test cpu::reg::test::should_set_reg ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_adc ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_add ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_addi ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_and ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_asr ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_call ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_com ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_dec ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_decw ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_di ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_ei ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_halt ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_icall ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_ijmp ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_in ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_inc ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_incw ... ok
Dec 14 02:39:21.776 INFO [stdout] test inst::inst::test::decode_jcc ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_jcs ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_jmp ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_jn ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_jnz ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_jp ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_jvc ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_jvs ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_jz ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_ld ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_ldd ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_ldi ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_ldsp ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_ldw ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_lsl ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_lsr ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_mov ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_neg ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_nop ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_or ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_out ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_pop ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_push ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_rcall ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_ret ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_reti ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_rjmp ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_sbc ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_st ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_std ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_sub ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_subi ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::decode_xor ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::encode_adc ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::encode_add ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::encode_addi ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::encode_and ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::encode_asr ... ok
Dec 14 02:39:21.777 INFO [stdout] test inst::inst::test::encode_call ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_com ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_dec ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_decw ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_di ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_ei ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_halt ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_icall ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_ijmp ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_in ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_inc ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_jp ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_jvc ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_jvs ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_jz ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_ld ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_ldd ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_ldi ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_ldsp ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_ldw ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_lsl ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_lsr ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_mov ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_neg ... ok
Dec 14 02:39:21.783 INFO [stdout] test inst::inst::test::encode_nop ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_jcs ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_jmp ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_jn ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_jcc ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_jnz ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_incw ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_or ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_out ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_rcall ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_sbc ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_reti ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_st ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_std ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_sub ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_subi ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_xor ... ok
Dec 14 02:39:21.791 INFO [stdout] test mem::bank::test::should_address_pages ... ok
Dec 14 02:39:21.791 INFO [stdout] test mem::page::test::ram_page_should_read_and_write ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_push ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_pop ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_rjmp ... ok
Dec 14 02:39:21.791 INFO [stdout] test inst::inst::test::encode_ret ... ok
Dec 14 02:39:21.886 INFO [stdout] test mem::page::test::rom_page_should_read ... ok
Dec 14 02:39:21.886 INFO [stdout] 
Dec 14 02:39:21.886 INFO [stdout] test result: ok. 231 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 02:39:21.886 INFO [stdout] 
Dec 14 02:39:21.887 INFO [stderr]      Running /target/debug/deps/spasm-2119d3d7fbc374cd
Dec 14 02:39:21.901 INFO [stdout] 
Dec 14 02:39:21.901 INFO [stdout] running 169 tests
Dec 14 02:39:21.919 INFO [stdout] test args::test::should_produce_bin_from_args ... ok
Dec 14 02:39:21.919 INFO [stdout] test args::test::should_produce_help_from_args ... ok
Dec 14 02:39:21.933 INFO [stdout] test args::test::should_produce_input_file_from_args ... ok
Dec 14 02:39:21.933 INFO [stdout] test args::test::should_produce_text_from_args ... ok
Dec 14 02:39:21.933 INFO [stdout] test args::test::should_produce_version_from_args ... ok
Dec 14 02:39:21.933 INFO [stdout] test args::test::should_produce_output_file_from_args ... ok
Dec 14 02:39:21.935 INFO [stdout] test asm::data::test::should_assemble_empty_data ... ok
Dec 14 02:39:21.935 INFO [stdout] test asm::data::test::should_assemble_data_from_numbers ... ok
Dec 14 02:39:21.935 INFO [stdout] test asm::data::test::should_assemble_data_from_string ... ok
Dec 14 02:39:21.935 INFO [stdout] test asm::data::test::should_assemble_data_from_ids ... ok
Dec 14 02:39:21.936 INFO [stdout] test asm::assembler::test::should_write_assembly ... ok
Dec 14 02:39:21.936 INFO [stdout] test asm::assembler::test::should_assemble ... ok
Dec 14 02:39:21.936 INFO [stdout] test asm::dir::test::should_preassemble_db ... ok
Dec 14 02:39:21.936 INFO [stdout] test asm::dir::test::should_preassemble_unknown_direct ... ok
Dec 14 02:39:21.936 INFO [stdout] test asm::data::test::should_fail_assemble_data_from_overflow_id ... ok
Dec 14 02:39:21.936 INFO [stdout] test asm::expr::test::should_asm_expr_to_areg ... ok
Dec 14 02:39:21.937 INFO [stdout] test asm::expr::test::should_asm_expr_to_addr ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::expr::test::should_asm_expr_to_immediate ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::expr::test::should_asm_expr_to_raddr ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::expr::test::should_asm_expr_to_reg ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::full::test::should_assemble_empty_program ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::full::test::should_assemble_non_empty ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_adc ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_add ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_addi ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_and ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_asr ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_call ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_com ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_dec ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_decw ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_di ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_ei ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::inst::full::test::should_asm_halt ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::dir::test::should_preassemble_org ... ok
Dec 14 02:39:21.943 INFO [stdout] test asm::expr::test::should_asm_expr_to_ioport ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::data::test::should_fail_assemble_data_from_invalid_type ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_inc ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_incw ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_jcc ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_jcs ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_jmp ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_jn ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_icall ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_in ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_ijmp ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_jvc ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_jz ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_jnz ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_jp ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_jvs ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_ld ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_ldd ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_ldw ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_ldi ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_lsr ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_mov ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_neg ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_nop ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_or ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_pop ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_ldsp ... ok
Dec 14 02:39:21.944 INFO [stdout] test asm::inst::full::test::should_asm_push ... ok
Dec 14 02:39:21.945 INFO [stdout] test asm::inst::full::test::should_asm_ret ... ok
Dec 14 02:39:21.945 INFO [stdout] test asm::inst::full::test::should_asm_rcall ... ok
Dec 14 02:39:21.955 INFO [stdout] test asm::inst::full::test::should_asm_sbc ... ok
Dec 14 02:39:21.955 INFO [stdout] test asm::inst::full::test::should_asm_reti ... ok
Dec 14 02:39:21.955 INFO [stdout] test asm::inst::full::test::should_asm_rjmp ... ok
Dec 14 02:39:21.967 INFO [stdout] test asm::inst::full::test::should_asm_sub ... ok
Dec 14 02:39:21.967 INFO [stdout] test asm::inst::full::test::should_asm_st ... ok
Dec 14 02:39:21.967 INFO [stdout] test asm::inst::full::test::should_asm_std ... ok
Dec 14 02:39:21.972 INFO [stdout] test asm::inst::full::test::should_asm_subi ... ok
Dec 14 02:39:21.972 INFO [stdout] test asm::inst::len::test::should_calculate_adc_len ... ok
Dec 14 02:39:21.972 INFO [stdout] test asm::inst::full::test::should_asm_xor ... ok
Dec 14 02:39:21.972 INFO [stdout] test asm::data::test::should_fail_assemble_data_from_overflow_numbers ... ok
Dec 14 02:39:21.972 INFO [stdout] test asm::inst::full::test::should_asm_out ... ok
Dec 14 02:39:21.974 INFO [stdout] test asm::inst::len::test::should_calculate_add_len ... ok
Dec 14 02:39:21.978 INFO [stdout] test asm::inst::len::test::should_calculate_sbc_len ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::len::test::should_calculate_st_len ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::len::test::should_calculate_sub_len ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::len::test::should_calculate_xor_len ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::full::test::should_asm_lsl ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_fail_pre_assemble_with_unknown_mnemo ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_add ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_and ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_asr ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_call ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_com ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_dec ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_di ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_ei ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_halt ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_icall ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_ijmp ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_in ... ok
Dec 14 02:39:21.979 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_inc ... ok
Dec 14 02:39:21.982 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_jcc ... ok
Dec 14 02:39:21.983 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_adc ... ok
Dec 14 02:39:21.983 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_jcs ... ok
Dec 14 02:39:21.983 INFO [stdout] test asm::inst::len::test::should_calculate_and_len ... ok
Dec 14 02:39:21.983 INFO [stdout] test asm::inst::len::test::should_calculate_or_len ... ok
Dec 14 02:39:21.986 INFO [stdout] test asm::inst::len::test::should_calculate_ld_len ... ok
Dec 14 02:39:21.987 INFO [stdout] test asm::inst::len::test::should_calculate_mov_len ... ok
Dec 14 02:39:21.987 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_jvc ... ok
Dec 14 02:39:21.987 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_jvs ... ok
Dec 14 02:39:21.987 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_ld ... ok
Dec 14 02:39:21.987 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_jz ... ok
Dec 14 02:39:22.003 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_jn ... ok
Dec 14 02:39:22.003 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_ldi ... ok
Dec 14 02:39:22.003 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_jnz ... ok
Dec 14 02:39:22.003 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_ldsp ... ok
Dec 14 02:39:22.003 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_jmp ... ok
Dec 14 02:39:22.003 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_jp ... ok
Dec 14 02:39:22.007 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_neg ... ok
Dec 14 02:39:22.007 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_lsl ... ok
Dec 14 02:39:22.007 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_lsr ... ok
Dec 14 02:39:22.007 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_mov ... ok
Dec 14 02:39:22.007 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_nop ... ok
Dec 14 02:39:22.007 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_or ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_ret ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_out ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_pop ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_rcall ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_reti ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_push ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_compute_line_numbers ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_xor ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_sub ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_addr_register ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_colon ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_ignore_blanks ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_comment ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_comma ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_comment_with_eol ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_decimal ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_directive ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_empty ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_eol ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_hexadecimal ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_ident ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_minus ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_register ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_string ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_string_with_eof_ending ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_string_with_eol_ending ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_string_with_scaped_cr ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_string_with_scaped_eol ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_string_with_scaped_slash ... ok
Dec 14 02:39:22.015 INFO [stdout] test asm::lexer::test::should_scan_string_with_scaped_tab ... ok
Dec 14 02:39:22.027 INFO [stdout] test asm::parser::test::should_fail_parse_two_consecutive_labels ... ok
Dec 14 02:39:22.027 INFO [stdout] test asm::parser::test::should_parse_binary_mnemo ... ok
Dec 14 02:39:22.027 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_sbc ... ok
Dec 14 02:39:22.027 INFO [stdout] test asm::parser::test::should_parse_labeled_directive ... ok
Dec 14 02:39:22.043 INFO [stdout] test asm::parser::test::should_parse_empty ... ok
Dec 14 02:39:22.043 INFO [stdout] test asm::parser::test::should_parse_labeled_mnemo ... ok
Dec 14 02:39:22.043 INFO [stdout] test asm::parser::test::should_parse_labeled_empty ... ok
Dec 14 02:39:22.043 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_rjmp ... ok
Dec 14 02:39:22.043 INFO [stdout] test asm::inst::pre::test::should_pre_assemble_st ... ok
Dec 14 02:39:22.056 INFO [stdout] test asm::parser::test::should_parse_nullary_directive ... ok
Dec 14 02:39:22.056 INFO [stdout] test asm::parser::test::should_parse_parameterized_directive ... ok
Dec 14 02:39:22.056 INFO [stdout] test asm::parser::test::should_parse_unary_mnemo ... ok
Dec 14 02:39:22.056 INFO [stdout] test asm::parser::test::should_parse_nullary_mnemo ... ok
Dec 14 02:39:22.056 INFO [stdout] test asm::pre::test::should_pre_assemble_declaring_inst_labels ... ok
Dec 14 02:39:22.056 INFO [stdout] test asm::pre::test::should_pre_assemble_program ... ok
Dec 14 02:39:22.056 INFO [stdout] test asm::number::test::should_convert_to_u8 ... ok
Dec 14 02:39:22.061 INFO [stdout] test asm::pre::test::should_pre_assemble_dup_inst_label_as_error ... ok
Dec 14 02:39:22.061 INFO [stdout] test asm::pre::test::should_pre_assemble_empty_prog ... ok
Dec 14 02:39:22.151 INFO [stdout] test args::test::should_parse_bin ... ok
Dec 14 02:39:22.163 INFO [stdout] test args::test::should_parse_help ... ok
Dec 14 02:39:22.163 INFO [stdout] 
Dec 14 02:39:22.163 INFO [stdout] test result: ok. 169 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 02:39:22.163 INFO [stdout] 
Dec 14 02:39:22.167 INFO [stdout] 
Dec 14 02:39:22.167 INFO [stderr]      Running /target/debug/deps/spm-fa174976861d84c5
Dec 14 02:39:22.167 INFO [stdout] running 8 tests
Dec 14 02:39:22.187 INFO [stdout] test args::test::should_produce_exec_from_args ... ok
Dec 14 02:39:22.187 INFO [stdout] test args::test::should_produce_help_from_args ... ok
Dec 14 02:39:22.187 INFO [stdout] test args::test::should_produce_version_from_args ... ok
Dec 14 02:39:22.203 INFO [stdout] test machine::test::should_output ... ok
Dec 14 02:39:22.203 INFO [stdout] test machine::test::should_exec ... ok
Dec 14 02:39:22.203 INFO [stdout] test args::test::should_produce_romfile_from_args ... ok
Dec 14 02:39:22.361 INFO [stdout] test args::test::should_parse_help ... ok
Dec 14 02:39:22.361 INFO [stderr]    Doc-tests simproc
Dec 14 02:39:22.361 INFO [stdout] test args::test::should_parse_exec ... ok
Dec 14 02:39:22.361 INFO [stdout] 
Dec 14 02:39:22.361 INFO [stdout] test result: ok. 8 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 02:39:22.361 INFO [stdout] 
Dec 14 02:39:23.147 INFO [stdout] 
Dec 14 02:39:23.147 INFO [stdout] running 0 tests
Dec 14 02:39:23.147 INFO [stdout] 
Dec 14 02:39:23.147 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 14 02:39:23.147 INFO [stdout] 
Dec 14 02:39:23.159 INFO [stderr] su: No module specific data is present
Dec 14 02:39:24.026 INFO running `"docker" "inspect" "aca7447b76b9ceb66ead9bfa1986c5f23adafd4e7751d8412211dca121eff2b1"`
Dec 14 02:39:24.452 INFO running `"docker" "rm" "-f" "aca7447b76b9ceb66ead9bfa1986c5f23adafd4e7751d8412211dca121eff2b1"`
Dec 14 02:39:24.799 INFO [stdout] aca7447b76b9ceb66ead9bfa1986c5f23adafd4e7751d8412211dca121eff2b1