01M2S7ZE8W8WKVV35YV1VKM4WG: test-memory

BasicConfig {
    output_rules: [
        "/tmp/*.txt",
        "/tmp/*.log",
        "%/tmp/debug/*.txt",
        "%/tmp/dsc/*.txt",
        "/tmp/core.*",
    ],
    rust_toolchain: None,
    target: Some(
        "helios-2.0",
    ),
    access_repos: [],
    publish: [],
    skip_clone: true,
}

Buildomat Job: 01M2S80470HXQXVPC9QK0VP038

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12026-09-18T03:25:55.853Zjob dependencies complete; ready to run (waiting for 13 m 43 s)
22026-09-18T03:25:57.268Zjob assigned to worker 01M2S8QPKPQT260WRHGSGYSM8Q [factory aws, i-0b46ce131d7a22024] (queued for 1 s)
32026-09-18T03:26:03.383Zdownloading input: /input/rbuild/out/crucible-nightly.sha256.txt
42026-09-18T03:26:03.497Zdownloaded input: /input/rbuild/out/crucible-nightly.sha256.txt
52026-09-18T03:26:03.497Zdownloading input: /input/rbuild/out/crucible-nightly.tar.gz
62026-09-18T03:26:06.918Zdownloaded input: /input/rbuild/out/crucible-nightly.tar.gz
72026-09-18T03:26:06.969Zdownloading input: /input/rbuild/out/crucible-pantry.sha256.txt
82026-09-18T03:26:07.035Zdownloaded input: /input/rbuild/out/crucible-pantry.sha256.txt
92026-09-18T03:26:07.035Zdownloading input: /input/rbuild/out/crucible-pantry.tar.gz
102026-09-18T03:26:07.619Zdownloaded input: /input/rbuild/out/crucible-pantry.tar.gz
112026-09-18T03:26:07.689Zdownloading input: /input/rbuild/out/crucible-utils.sha256.txt
122026-09-18T03:26:07.763Zdownloaded input: /input/rbuild/out/crucible-utils.sha256.txt
132026-09-18T03:26:07.763Zdownloading input: /input/rbuild/out/crucible-utils.tar
142026-09-18T03:26:08.384Zdownloaded input: /input/rbuild/out/crucible-utils.tar
152026-09-18T03:26:08.442Zdownloading input: /input/rbuild/out/crucible.sha256.txt
162026-09-18T03:26:08.507Zdownloaded input: /input/rbuild/out/crucible.sha256.txt
172026-09-18T03:26:08.507Zdownloading input: /input/rbuild/out/crucible.tar.gz
182026-09-18T03:26:10.041Zdownloaded input: /input/rbuild/out/crucible.tar.gz
192026-09-18T03:26:10.073Zdownloading input: /input/rbuild/work/rbins/crucible-downstairs.gz
202026-09-18T03:26:10.726Zdownloaded input: /input/rbuild/work/rbins/crucible-downstairs.gz
212026-09-18T03:26:10.726Zdownloading input: /input/rbuild/work/rbins/crucible-hammer.gz
222026-09-18T03:26:11.284Zdownloaded input: /input/rbuild/work/rbins/crucible-hammer.gz
232026-09-18T03:26:11.357Zdownloading input: /input/rbuild/work/rbins/crudd.gz
242026-09-18T03:26:11.639Zdownloaded input: /input/rbuild/work/rbins/crudd.gz
252026-09-18T03:26:11.639Zdownloading input: /input/rbuild/work/rbins/crutest.gz
262026-09-18T03:26:12.007Zdownloaded input: /input/rbuild/work/rbins/crutest.gz
272026-09-18T03:26:12.044Zdownloading input: /input/rbuild/work/rbins/dsc.gz
282026-09-18T03:26:12.332Zdownloaded input: /input/rbuild/work/rbins/dsc.gz
292026-09-18T03:26:12.354Zdownloading input: /input/rbuild/work/scripts/crudd-speed-battery.sh
302026-09-18T03:26:12.380Zdownloaded input: /input/rbuild/work/scripts/crudd-speed-battery.sh
312026-09-18T03:26:12.381Zdownloading input: /input/rbuild/work/scripts/perf-downstairs-tick.d
322026-09-18T03:26:12.397Zdownloaded input: /input/rbuild/work/scripts/perf-downstairs-tick.d
332026-09-18T03:26:12.397Zdownloading input: /input/rbuild/work/scripts/test_mem.sh
342026-09-18T03:26:12.415Zdownloaded input: /input/rbuild/work/scripts/test_mem.sh
352026-09-18T03:26:12.415Zdownloading input: /input/rbuild/work/scripts/upstairs_info.d
362026-09-18T03:26:12.439Zdownloaded input: /input/rbuild/work/scripts/upstairs_info.d
372026-09-18T03:26:12.455Zdownloading input: /input/rbuild/tmp/cargo-test-out.log
382026-09-18T03:26:13.637Zdownloaded input: /input/rbuild/tmp/cargo-test-out.log
 
392026-09-18T03:26:13.637Zstarting task 0: "setup"
402026-09-18T03:26:13.664Z++ uname -s
412026-09-18T03:26:13.664Z+ kern=SunOS
422026-09-18T03:26:13.664Z+ build_user=build
432026-09-18T03:26:13.664Z+ build_uid=12345
442026-09-18T03:26:13.664Z+ work_dir=/work
452026-09-18T03:26:13.664Z+ input_dir=/input
462026-09-18T03:26:13.664Z+ [[ 0 == 12345 ]]
472026-09-18T03:26:13.664Z+ case "$kern" in
482026-09-18T03:26:13.664Z+ groupadd -g 12345 build
492026-09-18T03:26:13.664Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
502026-09-18T03:26:15.623Z+ zfs create -o mountpoint=/work rpool/work
512026-09-18T03:26:15.822Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
522026-09-18T03:26:15.822Z+ home_fs=zfs
532026-09-18T03:26:15.822Z+ [[ zfs == autofs ]]
542026-09-18T03:26:15.822Z+ mkdir -p /home/build
552026-09-18T03:26:15.822Z+ chown build:build /home/build /work
562026-09-18T03:26:17.775Z+ chmod 0700 /home/build /work
572026-09-18T03:26:17.783Zprocess exited: duration 4177 ms, exit code 0
 
582026-09-18T03:26:17.809Zstarting task 1: "authentication"
592026-09-18T03:26:17.833ZWARNING: job store has no value for "GITHUB_TOKEN"; waiting for a value...
602026-09-18T03:26:56.028Zprocess exited: duration 38221 ms, exit code 0
 
612026-09-18T03:26:56.035Zstarting task 2: "build"
622026-09-18T03:26:56.037Z+ banner cores
632026-09-18T03:26:56.040Z
642026-09-18T03:26:56.040Z #### #### ##### ###### ####
652026-09-18T03:26:56.040Z # # # # # # # #
662026-09-18T03:26:56.040Z # # # # # ##### ####
672026-09-18T03:26:56.040Z # # # ##### # #
682026-09-18T03:26:56.040Z # # # # # # # # #
692026-09-18T03:26:56.040Z #### #### # # ###### ####
702026-09-18T03:26:56.040Z
712026-09-18T03:26:56.040Z+ pfexec coreadm -i /tmp/core.%f.%p -g /tmp/core.%f.%p -e global -e log -e proc-setid -e global-setid
722026-09-18T03:26:56.045Z+ banner unpack
732026-09-18T03:26:56.048Z
742026-09-18T03:26:56.048Z # # # # ##### ## #### # #
752026-09-18T03:26:56.048Z # # ## # # # # # # # # #
762026-09-18T03:26:56.048Z # # # # # # # # # # ####
772026-09-18T03:26:56.050Z # # # # # ##### ###### # # #
782026-09-18T03:26:56.050Z # # # ## # # # # # # #
792026-09-18T03:26:56.050Z #### # # # # # #### # #
802026-09-18T03:26:56.050Z
812026-09-18T03:26:56.050Z+ mkdir -p /var/tmp/bins
822026-09-18T03:26:56.050Z+ for t in "$input/rbins/"*.gz
832026-09-18T03:26:56.055Z++ basename /input/rbuild/work/rbins/crucible-downstairs.gz
842026-09-18T03:26:56.055Z+ b=crucible-downstairs.gz
852026-09-18T03:26:56.055Z+ b=crucible-downstairs
862026-09-18T03:26:56.055Z+ gunzip
872026-09-18T03:26:56.331Z+ chmod +x /var/tmp/bins/crucible-downstairs
882026-09-18T03:26:56.334Z+ for t in "$input/rbins/"*.gz
892026-09-18T03:26:56.334Z++ basename /input/rbuild/work/rbins/crucible-hammer.gz
902026-09-18T03:26:56.334Z+ b=crucible-hammer.gz
912026-09-18T03:26:56.334Z+ b=crucible-hammer
922026-09-18T03:26:56.334Z+ gunzip
932026-09-18T03:26:56.591Z+ chmod +x /var/tmp/bins/crucible-hammer
942026-09-18T03:26:56.593Z+ for t in "$input/rbins/"*.gz
952026-09-18T03:26:56.593Z++ basename /input/rbuild/work/rbins/crudd.gz
962026-09-18T03:26:56.593Z+ b=crudd.gz
972026-09-18T03:26:56.593Z+ b=crudd
982026-09-18T03:26:56.593Z+ gunzip
992026-09-18T03:26:56.836Z+ chmod +x /var/tmp/bins/crudd
1002026-09-18T03:26:56.838Z+ for t in "$input/rbins/"*.gz
1012026-09-18T03:26:56.839Z++ basename /input/rbuild/work/rbins/crutest.gz
1022026-09-18T03:26:56.839Z+ b=crutest.gz
1032026-09-18T03:26:56.839Z+ b=crutest
1042026-09-18T03:26:56.839Z+ gunzip
1052026-09-18T03:26:57.115Z+ chmod +x /var/tmp/bins/crutest
1062026-09-18T03:26:57.118Z+ for t in "$input/rbins/"*.gz
1072026-09-18T03:26:57.118Z++ basename /input/rbuild/work/rbins/dsc.gz
1082026-09-18T03:26:57.118Z+ b=dsc.gz
1092026-09-18T03:26:57.118Z+ b=dsc
1102026-09-18T03:26:57.118Z+ gunzip
1112026-09-18T03:26:57.249Z+ chmod +x /var/tmp/bins/dsc
1122026-09-18T03:26:57.252Z+ export BINDIR=/var/tmp/bins
1132026-09-18T03:26:57.252Z+ BINDIR=/var/tmp/bins
1142026-09-18T03:26:57.252Z+ export RUST_BACKTRACE=1
1152026-09-18T03:26:57.252Z+ RUST_BACKTRACE=1
1162026-09-18T03:26:57.252Z+ banner setup
1172026-09-18T03:26:57.252Z
1182026-09-18T03:26:57.252Z #### ###### ##### # # #####
1192026-09-18T03:26:57.252Z # # # # # # #
1202026-09-18T03:26:57.252Z #### ##### # # # # #
1212026-09-18T03:26:57.252Z # # # # # #####
1222026-09-18T03:26:57.252Z # # # # # # #
1232026-09-18T03:26:57.253Z #### ###### # #### #
1242026-09-18T03:26:57.253Z
1252026-09-18T03:26:57.253Z+ pfexec plimit -n 9123456 1088
1262026-09-18T03:26:57.289Z+ echo 'Setup self timeout'
1272026-09-18T03:26:57.289ZSetup self timeout
1282026-09-18T03:26:57.289Z+ jobpid=1088
1292026-09-18T03:26:57.292Z+ echo 'Setup debug logging'
1302026-09-18T03:26:57.292Z+ mkdir /tmp/debug
1312026-09-18T03:26:57.292ZSetup debug logging
1322026-09-18T03:26:57.292Z+ sleep 3600
1332026-09-18T03:26:57.292Z+ psrinfo -v
1342026-09-18T03:26:57.292Z+ df -h
1352026-09-18T03:26:57.295Z+ prstat -d d -mLc 1
1362026-09-18T03:26:57.298Z+ iostat -T d -xn 1
1372026-09-18T03:26:57.298Z+ mpstat -T d 1
1382026-09-18T03:26:57.298Z+ vmstat -T d -p 1
1392026-09-18T03:26:57.298Z+ pfexec dtrace -Z -s /input/rbuild/work/scripts/perf-downstairs-tick.d
1402026-09-18T03:26:57.298Z+ banner 512-memtest
1412026-09-18T03:26:57.298Z+ pfexec dtrace -Z -s /input/rbuild/work/scripts/upstairs_info.d
1422026-09-18T03:26:57.326Z####### # #####
1432026-09-18T03:26:57.326Z# ## # # # # ###### # # ##### ###### ####
1442026-09-18T03:26:57.326Z# # # # ## ## # ## ## # # #
1452026-09-18T03:26:57.326Z###### # ##### ##### # ## # ##### # ## # # ##### ####
1462026-09-18T03:26:57.326Z # # # # # # # # # # #
1472026-09-18T03:26:57.326Z# # # # # # # # # # # # #
1482026-09-18T03:26:57.326Z ##### ##### ####### # # ###### # # # ###### ####
1492026-09-18T03:26:57.326Z
1502026-09-18T03:26:57.329Z+ ptime -m bash /input/rbuild/work/scripts/test_mem.sh -b 512 -e 131072 -c 160
1512026-09-18T03:26:57.332ZUsing block size 512
1522026-09-18T03:26:57.332ZUsing extent size 131072
1532026-09-18T03:26:57.332ZUsing extent count 160
1542026-09-18T03:26:57.336Z/input/rbuild/work
1552026-09-18T03:26:57.341ZMemory usage test begins at September 18, 2026 at 03:26:56 AM UTC
1562026-09-18T03:26:57.344ZMemory usage values in kilobytes unless specified otherwise
1572026-09-18T03:26:57.418ZRegion with ES:131072 EC:160 BS:512 Size: 10 GiB Extent Size: 64 MiB
1582026-09-18T03:27:25.338Z PID RSS RSS/EC VSZ VSZ/EC HEAP HEAP/EC TOTAL TOTAL/EC EC
1592026-09-18T03:27:25.451Z 1157 113172 707 148908 930 97824 611 148908 930 160
1602026-09-18T03:27:25.538Z 1159 106944 668 142776 892 91388 571 142776 892 160
1612026-09-18T03:27:25.606Z 1158 112648 704 148412 927 97128 607 148412 927 160
1622026-09-18T03:27:25.711ZRegion:10 GiB Extent:64 MiB Total downstairs (pmap -x): 429 MiB
1632026-09-18T03:27:25.711ZSize of volume user gets : 10737418240
1642026-09-18T03:27:25.711ZSize on disk of all region dirs: 74726433 or 35.6G
1652026-09-18T03:27:25.711ZSize on disk of a single region: 24908811 or 11.9G
1662026-09-18T03:27:25.711Z Total Overage with 512 block size: 0.70%
1672026-09-18T03:27:25.711ZRegion Overage with 512 block size: 0.23%
1682026-09-18T03:27:26.675Z
1692026-09-18T03:27:26.804ZMemory usage test finished on September 18, 2026 at 03:27:25 AM UTC
1702026-09-18T03:27:26.804Z
1712026-09-18T03:27:26.804Zreal 29.273914419
1722026-09-18T03:27:26.804Zuser 36.176304083
1732026-09-18T03:27:26.804Zsys 26.568607509
1742026-09-18T03:27:26.804Ztrap 0.311173788
1752026-09-18T03:27:26.804Ztflt 0.001281307
1762026-09-18T03:27:26.804Zdflt 0.046445746
1772026-09-18T03:27:26.804Zkflt 0.006586422
1782026-09-18T03:27:26.804Zlock 56:10.819942932
1792026-09-18T03:27:26.804Zslp 2:10.085033656
1802026-09-18T03:27:26.804Zlat 52.390806213
1812026-09-18T03:27:26.804Zstop 0.004902048
1822026-09-18T03:27:26.804Z+ banner 4k-memtest
1832026-09-18T03:27:26.804Z#
1842026-09-18T03:27:26.804Z# # # # # # ###### # # ##### ###### #### #####
1852026-09-18T03:27:26.804Z# # # # ## ## # ## ## # # # #
1862026-09-18T03:27:26.804Z# # #### ##### # ## # ##### # ## # # ##### #### #
1872026-09-18T03:27:26.804Z####### # # # # # # # # # # #
1882026-09-18T03:27:26.804Z # # # # # # # # # # # # #
1892026-09-18T03:27:26.804Z # # # # # ###### # # # ###### #### #
1902026-09-18T03:27:26.804Z
1912026-09-18T03:27:26.805Z+ ptime -m bash /input/rbuild/work/scripts/test_mem.sh -b 4096 -e 16384 -c 160
1922026-09-18T03:27:26.805ZUsing block size 4096
1932026-09-18T03:27:26.805ZUsing extent size 16384
1942026-09-18T03:27:26.805ZUsing extent count 160
1952026-09-18T03:27:26.805Z/input/rbuild/work
1962026-09-18T03:27:26.805ZMemory usage test begins at September 18, 2026 at 03:27:25 AM UTC
1972026-09-18T03:27:26.805ZMemory usage values in kilobytes unless specified otherwise
1982026-09-18T03:27:26.806ZRegion with ES:16384 EC:160 BS:4096 Size: 10 GiB Extent Size: 64 MiB
1992026-09-18T03:27:48.719Z PID RSS RSS/EC VSZ VSZ/EC HEAP HEAP/EC TOTAL TOTAL/EC EC
2002026-09-18T03:27:48.767Z 1325 33120 207 67544 422 16512 103 67544 422 160
2012026-09-18T03:27:48.808Z 1323 31172 194 65596 409 14584 91 65596 409 160
2022026-09-18T03:27:48.875Z 1324 36248 226 70672 441 19724 123 70672 441 160
2032026-09-18T03:27:48.898ZRegion:10 GiB Extent:64 MiB Total downstairs (pmap -x): 199 MiB
2042026-09-18T03:27:48.898ZSize of volume user gets : 10737418240
2052026-09-18T03:27:48.898ZSize on disk of all region dirs: 64391073 or 30.7G
2062026-09-18T03:27:48.898ZSize on disk of a single region: 21463691 or 10.2G
2072026-09-18T03:27:48.909Z Total Overage with 4096 block size: 0.60%
2082026-09-18T03:27:48.909ZRegion Overage with 4096 block size: 0.20%
2092026-09-18T03:27:50.053Z
2102026-09-18T03:27:50.232ZMemory usage test finished on September 18, 2026 at 03:27:48 AM UTC
2112026-09-18T03:27:50.232Z
2122026-09-18T03:27:50.232Zreal 23.285627963
2132026-09-18T03:27:50.232Zuser 16.227884303
2142026-09-18T03:27:50.232Zsys 25.028760030
2152026-09-18T03:27:50.232Ztrap 0.102198472
2162026-09-18T03:27:50.232Ztflt 0.000467580
2172026-09-18T03:27:50.232Zdflt 0.002019098
2182026-09-18T03:27:50.232Zkflt 0.000029671
2192026-09-18T03:27:50.232Zlock 39:59.836978890
2202026-09-18T03:27:50.232Zslp 1:51.454842480
2212026-09-18T03:27:50.232Zlat 16.522439617
2222026-09-18T03:27:50.232Zstop 0.004968081
2232026-09-18T03:27:54.904Zprocess exited: duration 53858 ms, exit code 0
2242026-09-18T03:27:54.904Zexec warning: : stdio descriptors remain open after task exit; waiting 60 seconds for them to close
2252026-09-18T03:28:54.937Zexec warning: : stdout descriptor may be held open by a background process; giving up!
2262026-09-18T03:28:54.937Zexec warning: : stderr descriptor may be held open by a background process; giving up!
 
2272026-09-18T03:28:54.949Zfound 12 output files
2282026-09-18T03:28:54.950Zuploading: /tmp/test_mem_log.txt (2641815 bytes)
2292026-09-18T03:28:55.992Zuploaded: /tmp/test_mem_log.txt
2302026-09-18T03:28:55.992Zuploading: /tmp/debug/df.txt (1270 bytes)
2312026-09-18T03:28:57.003Zuploaded: /tmp/debug/df.txt
2322026-09-18T03:28:57.003Zuploading: /tmp/debug/iostat.txt (35731 bytes)
2332026-09-18T03:28:57.008Zupload warning: file "/tmp/debug/iostat.txt" changed size mid upload: 35731 -> 36335
2342026-09-18T03:28:58.015Zuploaded: /tmp/debug/iostat.txt
2352026-09-18T03:28:58.016Zuploading: /tmp/debug/mpstat.txt (86684 bytes)
2362026-09-18T03:28:58.022Zupload warning: file "/tmp/debug/mpstat.txt" changed size mid upload: 86684 -> 88877
2372026-09-18T03:28:59.030Zuploaded: /tmp/debug/mpstat.txt
2382026-09-18T03:28:59.030Zuploading: /tmp/debug/paging.txt (15702 bytes)
2392026-09-18T03:28:59.034Zupload warning: file "/tmp/debug/paging.txt" changed size mid upload: 15702 -> 16328
2402026-09-18T03:29:00.044Zuploaded: /tmp/debug/paging.txt
2412026-09-18T03:29:00.044Zuploading: /tmp/debug/perf.txt (53073 bytes)
2422026-09-18T03:29:00.051Zupload warning: file "/tmp/debug/perf.txt" changed size mid upload: 53073 -> 106017
2432026-09-18T03:29:01.059Zuploaded: /tmp/debug/perf.txt
2442026-09-18T03:29:01.059Zuploading: /tmp/debug/prstat.txt (161798 bytes)
2452026-09-18T03:29:01.071Zupload warning: file "/tmp/debug/prstat.txt" changed size mid upload: 161798 -> 169571
2462026-09-18T03:29:02.076Zuploaded: /tmp/debug/prstat.txt
2472026-09-18T03:29:02.076Zuploading: /tmp/debug/psrinfo.txt (1528 bytes)
2482026-09-18T03:29:03.120Zuploaded: /tmp/debug/psrinfo.txt
2492026-09-18T03:29:03.120Zuploading: /tmp/debug/upinfo.txt (4760 bytes)
2502026-09-18T03:29:04.133Zuploaded: /tmp/debug/upinfo.txt
2512026-09-18T03:29:04.133Zuploading: /tmp/dsc/downstairs-8810.txt (8907 bytes)
2522026-09-18T03:29:05.177Zuploaded: /tmp/dsc/downstairs-8810.txt
2532026-09-18T03:29:05.177Zuploading: /tmp/dsc/downstairs-8820.txt (7728 bytes)
2542026-09-18T03:29:06.195Zuploaded: /tmp/dsc/downstairs-8820.txt
2552026-09-18T03:29:06.195Zuploading: /tmp/dsc/downstairs-8830.txt (7729 bytes)
2562026-09-18T03:29:07.204Zuploaded: /tmp/dsc/downstairs-8830.txt