Nov 16 16:05:22.802 INFO testing razielgn/nes against try#2e026d6e5d7621634147ad4c8074f1d964dbb1be for pr-55982
Nov 16 16:05:22.802 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-0/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-0/pr-55982/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/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 +2e026d6e5d7621634147ad4c8074f1d964dbb1be-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"`
Nov 16 16:05:23.019 INFO [stdout] ed65ee9afc0aa22c4423fe29539d3a832f2aa8ff2e3bf2d6f56fe905bf036821
Nov 16 16:05:23.021 INFO running `"docker" "start" "-a" "ed65ee9afc0aa22c4423fe29539d3a832f2aa8ff2e3bf2d6f56fe905bf036821"`
Nov 16 16:05:23.450 INFO [stderr] usermod: no changes
Nov 16 16:05:23.499 INFO [stderr]    Compiling version_check v0.1.4
Nov 16 16:05:23.499 INFO [stderr]    Compiling cfg-if v0.1.5
Nov 16 16:05:23.500 INFO [stderr]    Compiling libc v0.2.43
Nov 16 16:05:23.500 INFO [stderr]    Compiling ucd-util v0.1.1
Nov 16 16:05:23.500 INFO [stderr]    Compiling regex v1.0.5
Nov 16 16:05:23.500 INFO [stderr]    Compiling utf8-ranges v1.0.1
Nov 16 16:05:23.500 INFO [stderr]    Compiling quick-error v1.2.2
Nov 16 16:05:23.502 INFO [stderr]    Compiling termcolor v1.0.4
Nov 16 16:05:23.687 INFO [stderr]    Compiling log v0.4.5
Nov 16 16:05:23.934 INFO [stderr]    Compiling humantime v1.1.1
Nov 16 16:05:29.583 INFO [stderr]    Compiling atty v0.2.11
Nov 16 16:05:30.327 INFO [stderr]    Compiling regex-syntax v0.6.2
Nov 16 16:05:30.330 INFO [stderr]    Compiling lazy_static v1.1.0
Nov 16 16:05:30.332 INFO [stderr]    Compiling memchr v2.1.0
Nov 16 16:05:31.544 INFO [stderr]    Compiling thread_local v0.3.6
Nov 16 16:05:33.915 INFO [stderr]    Compiling aho-corasick v0.6.8
Nov 16 16:05:33.915 INFO [stderr]    Compiling nom v4.0.0
Nov 16 16:06:15.190 INFO [stderr]    Compiling env_logger v0.5.13
Nov 16 16:06:19.098 INFO [stderr]    Compiling nes v0.1.0 (/source)
Nov 16 16:06:23.837 INFO [stderr]     Finished dev [optimized + debuginfo] target(s) in 1m 00s
Nov 16 16:06:23.839 INFO [stderr] su: No module specific data is present
Nov 16 16:06:24.733 INFO running `"docker" "inspect" "ed65ee9afc0aa22c4423fe29539d3a832f2aa8ff2e3bf2d6f56fe905bf036821"`
Nov 16 16:06:25.031 INFO running `"docker" "rm" "-f" "ed65ee9afc0aa22c4423fe29539d3a832f2aa8ff2e3bf2d6f56fe905bf036821"`
Nov 16 16:06:25.311 INFO [stdout] ed65ee9afc0aa22c4423fe29539d3a832f2aa8ff2e3bf2d6f56fe905bf036821
Nov 16 16:06:25.315 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-0/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-0/pr-55982/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/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 +2e026d6e5d7621634147ad4c8074f1d964dbb1be-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"`
Nov 16 16:06:25.972 INFO [stdout] 2f0902352b3c4457c6f7c4a39d75da29690622ef5121ce13ffc9b632af23676a
Nov 16 16:06:25.977 INFO running `"docker" "start" "-a" "2f0902352b3c4457c6f7c4a39d75da29690622ef5121ce13ffc9b632af23676a"`
Nov 16 16:06:27.039 INFO [stderr] usermod: no changes
Nov 16 16:06:27.188 INFO [stderr]    Compiling nes v0.1.0 (/source)
Nov 16 16:06:32.047 INFO [stderr]     Finished dev [optimized + debuginfo] target(s) in 4.98s
Nov 16 16:06:32.052 INFO [stderr] su: No module specific data is present
Nov 16 16:06:32.935 INFO running `"docker" "inspect" "2f0902352b3c4457c6f7c4a39d75da29690622ef5121ce13ffc9b632af23676a"`
Nov 16 16:06:33.223 INFO running `"docker" "rm" "-f" "2f0902352b3c4457c6f7c4a39d75da29690622ef5121ce13ffc9b632af23676a"`
Nov 16 16:06:33.486 INFO [stdout] 2f0902352b3c4457c6f7c4a39d75da29690622ef5121ce13ffc9b632af23676a
Nov 16 16:06:33.496 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-55982/worker-0/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-0/pr-55982/try#2e026d6e5d7621634147ad4c8074f1d964dbb1be:/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 +2e026d6e5d7621634147ad4c8074f1d964dbb1be-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"`
Nov 16 16:06:33.987 INFO [stdout] a07a6fbf0554f663249c3017b323007a52975cab27e91492b6d09922ce3ec0c2
Nov 16 16:06:33.991 INFO running `"docker" "start" "-a" "a07a6fbf0554f663249c3017b323007a52975cab27e91492b6d09922ce3ec0c2"`
Nov 16 16:06:35.551 INFO [stderr] usermod: no changes
Nov 16 16:06:35.691 INFO [stderr]     Finished dev [optimized + debuginfo] target(s) in 0.09s
Nov 16 16:06:35.691 INFO [stderr]      Running /target/debug/deps/nes-58165b85f431d8e8
Nov 16 16:06:35.703 INFO [stdout] 
Nov 16 16:06:35.703 INFO [stdout] running 38 tests
Nov 16 16:06:35.703 INFO [stdout] test cpu::test::lda_absolute_x ... ok
Nov 16 16:06:35.703 INFO [stdout] test cpu::test::lda_absolute ... ok
Nov 16 16:06:35.703 INFO [stdout] test cpu::test::jmp_indirect ... ok
Nov 16 16:06:35.703 INFO [stdout] test cpu::test::bpl_relative_not_branch ... ok
Nov 16 16:06:35.703 INFO [stdout] test cpu::test::bpl_relative_branch ... ok
Nov 16 16:06:35.703 INFO [stdout] test cpu::test::lda_immediate ... ok
Nov 16 16:06:35.703 INFO [stdout] test cpu::test::lda_indexed_indirect ... ok
Nov 16 16:06:35.703 INFO [stdout] test cpu::test::asl_accumulator ... ok
Nov 16 16:06:35.703 INFO [stdout] test cpu::test::lda_indirect_indexed ... ok
Nov 16 16:06:35.715 INFO [stdout] test cpu::test::lda_indirect_indexed_page_crossing ... ok
Nov 16 16:06:35.715 INFO [stdout] test cpu::test::lda_indirect_indexed_page_wraparound ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::lda_absolute_x_page_cross ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::lda_absolute_y ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::lda_absolute_y_page_cross ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::lda_zero_page ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::lda_indexed_indirect_page_wraparound ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::lda_zero_page_x ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::bit_ops_on_p ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::nop_implied ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::reset ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::rol_absolute_x_dummy_read ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::sta_absolute_y_dummy_read ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::sta_indirect_indexed_dummy_read ... ok
Nov 16 16:06:35.739 INFO [stdout] test memory::test::ram_wraparound ... ok
Nov 16 16:06:35.739 INFO [stdout] test ppu::tests::control::background_pattern_table_addr ... ok
Nov 16 16:06:35.739 INFO [stdout] test cpu::test::ldx_zero_page_y ... ok
Nov 16 16:06:35.739 INFO [stdout] test ppu::tests::control::master_slave_select ... ok
Nov 16 16:06:35.739 INFO [stdout] test ppu::tests::control::name_table_addr ... ok
Nov 16 16:06:35.739 INFO [stdout] test ppu::tests::control::nmi_at_next_vblank ... ok
Nov 16 16:06:35.739 INFO [stdout] test ppu::tests::control::sprite_pattern_table_addr ... ok
Nov 16 16:06:35.739 INFO [stdout] test ppu::tests::control::sprite_size ... ok
Nov 16 16:06:35.739 INFO [stdout] test ppu::tests::control::vram_addr_incr ... ok
Nov 16 16:06:35.739 INFO [stdout] test ppu::tests::mask::grayscale ... ok
Nov 16 16:06:35.739 INFO [stdout] test ppu::tests::oam_write_and_read ... ok
Nov 16 16:06:35.744 INFO [stdout] test ppu::tests::scroll_and_addr_write_example ... ok
Nov 16 16:06:35.775 INFO [stdout] test ppu::tests::vblank_has_started_and_reading_status_resets_it ... ok
Nov 16 16:06:35.788 INFO [stdout] test ppu::tests::vblank_has_ended ... ok
Nov 16 16:06:35.799 INFO [stdout] test ppu::tests::odd_frames_are_shorter_by_one_cycle ... ok
Nov 16 16:06:35.799 INFO [stderr]      Running /target/debug/deps/blargg-7ae78493e6239183
Nov 16 16:06:35.799 INFO [stdout] 
Nov 16 16:06:35.799 INFO [stdout] test result: ok. 38 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 16 16:06:35.799 INFO [stdout] 
Nov 16 16:06:35.799 INFO [stdout] 
Nov 16 16:06:35.799 INFO [stdout] running 33 tests
Nov 16 16:06:35.799 INFO [stdout] test cpu_interrupts_v2::branch_delays_irq ... ignored
Nov 16 16:06:35.807 INFO [stdout] test cpu_interrupts_v2::cli_latency ... ignored
Nov 16 16:06:35.808 INFO [stdout] test cpu_interrupts_v2::irq_and_dma ... ignored
Nov 16 16:06:35.808 INFO [stdout] test cpu_interrupts_v2::nmi_and_brk ... ignored
Nov 16 16:06:35.819 INFO [stdout] test cpu_interrupts_v2::nmi_and_irq ... ignored
Nov 16 16:06:35.819 INFO [stdout] test cpu_reset::registers ... ignored
Nov 16 16:06:35.819 INFO [stdout] test instr_misc::dummy_reads_apu ... ignored
Nov 16 16:06:36.583 INFO [stdout] test instr_misc::branch_wrap ... ok
Nov 16 16:06:36.583 INFO [stdout] test instr_misc::abs_x_wrap ... ok
Nov 16 16:06:36.855 INFO [stdout] test instr_test_v5::basics ... ok
Nov 16 16:06:39.120 INFO [stdout] test instr_test_v5::brk ... ok
Nov 16 16:06:39.537 INFO [stdout] test instr_misc::dummy_reads ... ok
Nov 16 16:06:39.683 INFO [stdout] test instr_test_v5::branches ... ok
Nov 16 16:06:40.454 INFO [stdout] test instr_test_v5::immediate ... ok
Nov 16 16:06:41.743 INFO [stdout] test instr_test_v5::jmp_jsr ... ok
Nov 16 16:06:42.463 INFO [stdout] test instr_test_v5::absolute ... ok
Nov 16 16:06:43.447 INFO [stdout] test instr_test_v5::rti ... ok
Nov 16 16:06:43.463 INFO [stdout] test instr_test_v5::implied ... ok
Nov 16 16:06:43.677 INFO [stdout] test cpu_reset::ram_after_reset ... ok
Nov 16 16:06:43.677 INFO [stdout] test instr_test_v5::stack ... ignored
Nov 16 16:06:44.247 INFO [stdout] test instr_test_v5::special ... ok
Nov 16 16:06:44.679 INFO [stdout] test instr_test_v5::rts ... ok
Nov 16 16:06:44.679 INFO [stdout] test instr_timing::branch_timing ... ignored
Nov 16 16:06:44.679 INFO [stdout] test instr_timing::instr_timing ... ignored
Nov 16 16:06:46.083 INFO [stdout] test oam_read ... ok
Nov 16 16:06:46.603 INFO [stdout] test instr_test_v5::ind_x ... ok
Nov 16 16:06:47.839 INFO [stdout] test instr_test_v5::ind_y ... ok
Nov 16 16:06:49.419 INFO [stdout] test instr_test_v5::zero_page ... ok
Nov 16 16:06:52.579 INFO [stdout] test instr_test_v5::abs_xy ... ok
Nov 16 16:06:55.277 INFO [stdout] test instr_test_v5::zp_xy ... ok
Nov 16 16:07:08.015 INFO [stdout] test instr_test_v5::all_instrs ... ok
Nov 16 16:07:12.215 INFO [stdout] test instr_test_v5::official_only ... ok
Nov 16 16:07:22.745 INFO [stdout] test oam_stress ... ok
Nov 16 16:07:22.745 INFO [stdout] 
Nov 16 16:07:22.745 INFO [stdout] test result: ok. 23 passed; 0 failed; 10 ignored; 0 measured; 0 filtered out
Nov 16 16:07:22.746 INFO [stdout] 
Nov 16 16:07:22.746 INFO [stderr]      Running /target/debug/deps/nestest-360a0ca979c22fa3
Nov 16 16:07:22.751 INFO [stdout] 
Nov 16 16:07:22.752 INFO [stdout] running 1 test
Nov 16 16:07:22.852 INFO [stdout] test nestest ... ok
Nov 16 16:07:22.853 INFO [stderr]      Running /target/debug/deps/rom-faebedb76d58784c
Nov 16 16:07:22.853 INFO [stdout] 
Nov 16 16:07:22.853 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 16 16:07:22.853 INFO [stdout] 
Nov 16 16:07:22.855 INFO [stdout] 
Nov 16 16:07:22.855 INFO [stdout] running 1 test
Nov 16 16:07:22.856 INFO [stdout] test nestest_decode ... ok
Nov 16 16:07:22.856 INFO [stdout] 
Nov 16 16:07:22.856 INFO [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Nov 16 16:07:22.857 INFO [stdout] 
Nov 16 16:07:22.858 INFO [stderr] su: No module specific data is present
Nov 16 16:07:23.467 INFO running `"docker" "inspect" "a07a6fbf0554f663249c3017b323007a52975cab27e91492b6d09922ce3ec0c2"`
Nov 16 16:07:23.841 INFO running `"docker" "rm" "-f" "a07a6fbf0554f663249c3017b323007a52975cab27e91492b6d09922ce3ec0c2"`
Nov 16 16:07:24.079 INFO [stdout] a07a6fbf0554f663249c3017b323007a52975cab27e91492b6d09922ce3ec0c2