niks3-go-unit-tests log

succeeded `niks3-go-unit-tests` `checks.aarch64-linux.go-unit-tests` · build #290 · raw

1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenScriptFails97=== CONT TestScriptTokenEmptyCommand98--- PASS: TestScriptTokenEmptyCommand (0.00s)99=== CONT TestConvertHashToNix32100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestScriptTokenBadJSON102=== CONT TestClientSignaturesByStorePath103--- PASS: TestClientSignaturesByStorePath (0.00s)104=== CONT TestFileTokenMissing105=== CONT TestStreamPushReportsSignatures106=== CONT TestStreamPushRequestLine107--- PASS: TestFileTokenMissing (0.00s)108=== CONT TestScriptTokenEmptyToken109=== CONT TestStreamPushGivesUpOnDeadServer110=== CONT TestStreamPushIsolatesFailures111=== CONT TestStreamPushBatchesUnderLoad112=== CONT TestStreamPushReportsEveryPath113=== CONT TestShellSplitErrors114=== CONT TestShellSplit115=== CONT TestEncodeNixBase32WithRealHash116=== CONT TestResolveStorePath117=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1182026/10/01 07:36:34 ERROR Upload failed error="connection refused" count=201192026/10/01 07:36:34 ERROR Server seems unavailable, giving up on batch untried=17120=== CONT TestRateLimiterFeedback1212026/10/01 07:36:34 ERROR Upload failed error=boom count=1122=== RUN TestRateLimiterFeedback/429_enables_limiter1232026/10/01 07:36:34 ERROR Upload failed error="bad path" count=3124=== PAUSE TestRateLimiterFeedback/429_enables_limiter125=== CONT TestPathInfoCACompatibility126=== CONT TestParsePathInfoJSONMultiplePaths1272026/10/01 07:36:34 WARN Rate limiter enabled after throttle name=server-test rate=5128=== CONT TestParsePathInfoJSON129=== CONT TestPathInfoHashCompatibility130=== CONT TestGetStorePathHash131=== CONT TestSetClientTLS132=== RUN TestConvertHashToNix32/SRI_format_to_Nix32133--- PASS: TestScriptTokenScriptFails (0.00s)134=== CONT TestScriptTokenNoExpiryRerunsEveryCall1352026/10/01 07:36:34 ERROR Upload failed error=boom count=1136=== RUN TestPathInfoCACompatibility/null_ca_field137--- PASS: TestStreamPushReportsSignatures (0.00s)138=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)139=== PAUSE TestPathInfoCACompatibility/null_ca_field140=== RUN TestPathInfoCACompatibility/old_string_format_-_text141=== CONT TestFileTokenEmpty142=== CONT TestSetClientTLSErrors143=== CONT TestSetClientTLSDoesNotMutateDefaultTransport144=== CONT TestScriptTokenCachesUntilRefresh145=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths146=== RUN TestParsePathInfoJSON/Nix_format147--- PASS: TestShellSplitErrors (0.00s)148--- PASS: TestShellSplit (0.00s)149--- PASS: TestEncodeNixBase32WithRealHash (0.00s)150--- PASS: TestStreamPushReportsEveryPath (0.00s)151--- PASS: TestStreamPushIsolatesFailures (0.00s)152--- PASS: TestScriptTokenBadJSON (0.00s)153=== CONT TestFilterOversizedClosures154=== RUN TestFilterOversizedClosures/no_limit_keeps_everything1552026/10/01 07:36:34 WARN Rate limiter enabled after throttle name=server-test rate=5156=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything157--- PASS: TestResolveStorePath (0.00s)158=== CONT TestEncodeNixBase321592026/10/01 07:36:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42809160=== RUN TestEncodeNixBase32/test_string_hash161=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped162=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped163=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)164=== RUN TestFilterOversizedClosures/all_closures_skipped165=== PAUSE TestFilterOversizedClosures/all_closures_skipped166=== RUN TestGetStorePathHash/valid_store_path167=== CONT TestStaticToken168=== CONT TestDumpPathSingleFile169=== PAUSE TestGetStorePathHash/valid_store_path170=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32171=== RUN TestRateLimiterFeedback/503_enables_limiter172=== PAUSE TestRateLimiterFeedback/503_enables_limiter173=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter174=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter175=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter176=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter1772026/10/01 07:36:34 WARN Rate limiter backed off name=server-test rate=51782026/10/01 07:36:34 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:42809179=== CONT TestUploadMultipart_SupersededByPeer180=== RUN TestUploadMultipart_SupersededByPeer/exists181=== PAUSE TestUploadMultipart_SupersededByPeer/exists182=== RUN TestUploadMultipart_SupersededByPeer/missing183=== PAUSE TestUploadMultipart_SupersededByPeer/missing184--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)185=== CONT TestPartSizeForNAR186=== PAUSE TestEncodeNixBase32/test_string_hash187=== CONT TestDumpPathWriterError188=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text189=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon190=== CONT TestFileTokenReadsAndCaches191=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths192=== PAUSE TestParsePathInfoJSON/Nix_format193=== RUN TestGetStorePathHash/basename_without_hyphen_should_error194=== RUN TestConvertHashToNix32/already_Nix32_format195=== CONT TestDumpPathMatchesNix196=== PAUSE TestConvertHashToNix32/already_Nix32_format197=== RUN TestParsePathInfoJSON/Lix_format198=== PAUSE TestParsePathInfoJSON/Lix_format199=== RUN TestParsePathInfoJSON/empty_input200=== PAUSE TestParsePathInfoJSON/empty_input201=== RUN TestParsePathInfoJSON/whitespace_only202=== PAUSE TestParsePathInfoJSON/whitespace_only203=== CONT TestCaseHackSuffix204=== RUN TestPartSizeForNAR/zero_stays_at_minimum205=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon206=== RUN TestConvertHashToNix32/invalid_format207=== CONT TestUploadMultipart_PartsInParallel208=== RUN TestEncodeNixBase32/empty_input209=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error210=== CONT TestRegisterUploadedObjectReusesConnections211=== RUN TestParsePathInfoJSON/invalid_JSON212=== CONT TestFilterOversizedClosures/no_limit_keeps_everything213--- PASS: TestScriptTokenEmptyToken (0.00s)214=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum215=== PAUSE TestConvertHashToNix32/invalid_format216=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths217=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths218=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter219=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive220=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive221=== RUN TestPathInfoCACompatibility/new_structured_format_-_text222=== CONT TestRateLimiterFeedback/503_enables_limiter223=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text224=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method225=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method226=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2272026/10/01 07:36:34 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000228=== RUN TestPartSizeForNAR/small_stays_at_minimum229=== CONT TestUploadMultipart_SupersededByPeer/exists2302026/10/01 07:36:34 WARN Rate limiter enabled after throttle name=server-test rate=5231=== PAUSE TestPartSizeForNAR/small_stays_at_minimum2322026/10/01 07:36:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:45789233=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum234=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum235=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts236=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts237=== RUN TestPartSizeForNAR/1_TiB238=== PAUSE TestPartSizeForNAR/1_TiB239=== RUN TestSetClientTLSErrors/missing_cert_file240=== PAUSE TestEncodeNixBase32/empty_input241=== PAUSE TestParsePathInfoJSON/invalid_JSON242=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error243=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter244--- PASS: TestStaticToken (0.00s)245=== CONT TestFilterOversizedClosures/all_closures_skipped246=== RUN TestSetClientTLS/rejects_connection_without_client_cert247=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI248=== CONT TestUploadMultipart_SupersededByPeer/missing249=== CONT TestRateLimiterFeedback/429_enables_limiter2502026/10/01 07:36:34 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50251=== PAUSE TestSetClientTLSErrors/missing_cert_file2522026/10/01 07:36:34 WARN Rate limiter backed off name=server-test rate=5253=== RUN TestSetClientTLSErrors/missing_key_file254=== PAUSE TestSetClientTLSErrors/missing_key_file255=== RUN TestSetClientTLSErrors/missing_ca_file256=== PAUSE TestSetClientTLSErrors/missing_ca_file257=== RUN TestSetClientTLSErrors/invalid_ca_file258=== PAUSE TestSetClientTLSErrors/invalid_ca_file259=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths260=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths261=== CONT TestConvertHashToNix32/SRI_format_to_Nix32262=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method263=== CONT TestPathInfoCACompatibility/new_structured_format_-_text264=== CONT TestPathInfoCACompatibility/old_string_format_-_text265=== CONT TestParsePathInfoJSON/Nix_format266=== CONT TestEncodeNixBase32/test_string_hash267=== CONT TestSetClientTLSErrors/missing_cert_file2682026/10/01 07:36:34 WARN Rate limiter enabled after throttle name=server-test rate=5269=== CONT TestParsePathInfoJSON/whitespace_only2702026/10/01 07:36:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:39161271=== CONT TestSetClientTLSErrors/invalid_ca_file272=== CONT TestParsePathInfoJSON/empty_input273=== CONT TestSetClientTLSErrors/missing_ca_file2742026/10/01 07:36:34 WARN Rate limiter backed off name=server-test rate=5275=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error276=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI277=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512278=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512279=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)280=== CONT TestPathInfoCACompatibility/null_ca_field281=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI282=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon283=== CONT TestParsePathInfoJSON/Lix_format284=== CONT TestSetClientTLSErrors/missing_key_file285=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive286=== CONT TestConvertHashToNix32/invalid_format287=== CONT TestConvertHashToNix32/already_Nix32_format288--- PASS: TestFileTokenEmpty (0.00s)289--- PASS: TestDoServerRequestAttachesToken (0.01s)290=== RUN TestPartSizeForNAR/5_TiB_S3_max_object291=== CONT TestParsePathInfoJSON/invalid_JSON292=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert293=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error294=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error295=== CONT TestEncodeNixBase32/empty_input296=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512297--- PASS: TestFileTokenReadsAndCaches (0.00s)298--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)299--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)300=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object301=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA302=== CONT TestGetStorePathHash/valid_store_path303=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error304=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error305=== CONT TestGetStorePathHash/basename_without_hyphen_should_error306--- PASS: TestFilterOversizedClosures (0.00s)307 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)308 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)309 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)310=== RUN TestPartSizeForNAR/capped_at_5_GiB311=== PAUSE TestPartSizeForNAR/capped_at_5_GiB312=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA313--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)314 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)315 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)316=== CONT TestPartSizeForNAR/zero_stays_at_minimum317=== CONT TestPartSizeForNAR/capped_at_5_GiB318=== CONT TestPartSizeForNAR/5_TiB_S3_max_object319=== CONT TestPartSizeForNAR/1_TiB320=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts321=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum322=== CONT TestPartSizeForNAR/small_stays_at_minimum323=== RUN TestSetClientTLS/preserves_debug_logging_transport324=== PAUSE TestSetClientTLS/preserves_debug_logging_transport325=== CONT TestSetClientTLS/rejects_connection_without_client_cert326=== CONT TestSetClientTLS/preserves_debug_logging_transport327--- PASS: TestPathInfoCACompatibility (0.03s)328 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)329 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)330 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)331 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)332 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)333--- PASS: TestConvertHashToNix32 (0.03s)334 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)335 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)336 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)337=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA338--- PASS: TestParsePathInfoJSON (0.03s)339 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)340 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)341 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)342 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)343 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)344--- PASS: TestEncodeNixBase32 (0.03s)345 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)346 --- PASS: TestEncodeNixBase32/empty_input (0.00s)347--- PASS: TestPathInfoHashCompatibility (0.03s)348 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)349 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)350 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)351 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)352--- PASS: TestGetStorePathHash (0.03s)353 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)354 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)355 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)356 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)357--- PASS: TestRateLimiterFeedback (0.00s)358 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)359 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)360 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)361 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)362--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)363 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)364 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)365--- PASS: TestPartSizeForNAR (0.03s)366 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)368 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)369 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)370 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)371 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)372 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)373--- PASS: TestSetClientTLSErrors (0.03s)374 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)375 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)376 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)377 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)378--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)379--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)380--- PASS: TestDumpPathSingleFile (0.04s)3812026/10/01 07:36:34 http: TLS handshake error from 127.0.0.1:34982: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.03s)383 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)386--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)387--- PASS: TestStreamPushRequestLine (0.05s)388--- PASS: TestCaseHackSuffix (0.06s)389--- PASS: TestDumpPathWriterError (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.13s)392--- PASS: TestUploadMultipart_PartsInParallel (0.65s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres1049012412/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres1049012412/data -l logfile start422423/build/postgres1049012412:5432 - no response4242026-10-01 07:36:36.313 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 07:36:36.314 UTC [128] LOG: listening on Unix socket "/build/postgres1049012412/.s.PGSQL.5432"4262026-10-01 07:36:36.320 UTC [135] LOG: database system was shut down at 2026-10-01 07:36:36 UTC4272026-10-01 07:36:36.324 UTC [128] LOG: database system is ready to accept connections428/build/postgres1049012412:5432 - accepting connections429{"timestamp":"2026-10-01T07:36:36.509355107Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"fa8ece9b-0623-4a2f-8de7-17ac1e5cad41","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(203)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestResolveDBConnectionString467=== PAUSE TestResolveDBConnectionString468=== RUN TestLeadElectsOneAndHandsOver469=== PAUSE TestLeadElectsOneAndHandsOver470=== RUN TestLeadIncumbentWinsAfterRestart4712026-10-01 07:36:36.688 UTC [375] ERROR: relation "goose_db_version" does not exist at character 364722026-10-01 07:36:36.688 UTC [375] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4732026/10/01 07:36:36 OK 20241026095416_initial_model.sql (9.46ms)4742026/10/01 07:36:36 OK 20251210153512_drop_unused_gin_index.sql (2.8ms)4752026/10/01 07:36:36 OK 20251218171726_add_pins.sql (4.41ms)4762026/10/01 07:36:36 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)4772026/10/01 07:36:36 OK 20260905000000_add_claims.sql (3.55ms)4782026/10/01 07:36:36 OK 20260920000000_drop_claims.sql (2.52ms)4792026/10/01 07:36:36 OK 20260923120000_add_pushes.sql (1.83ms)4802026/10/01 07:36:36 goose: successfully migrated database to version: 202609231200004812026/10/01 07:36:36 OK 1_commit_pending_closure.sql (3.62ms)4822026/10/01 07:36:36 OK 2_object_stats_trigger.sql (2.26ms)4832026/10/01 07:36:36 OK 3_commit_push.sql (1.76ms)4842026/10/01 07:36:36 goose: up to current file version: 34852026/10/01 07:36:36 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 07:36:37 INFO lead: released remote=192.0.2.1:12344872026/10/01 07:36:37 INFO lead: acquired remote=192.0.2.1:12344882026/10/01 07:36:37 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadIncumbentWinsAfterRestart (0.80s)490=== RUN TestLeadEndsOnShutdown491=== PAUSE TestLeadEndsOnShutdown492=== RUN TestGCAdvisoryLockBlocksConcurrentRun4932026-10-01 07:36:37.467 UTC [385] ERROR: relation "goose_db_version" does not exist at character 364942026-10-01 07:36:37.467 UTC [385] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4952026/10/01 07:36:37 OK 20241026095416_initial_model.sql (7ms)4962026/10/01 07:36:37 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)4972026/10/01 07:36:37 OK 20251218171726_add_pins.sql (2.52ms)4982026/10/01 07:36:37 OK 20260628120000_add_object_size_and_stats.sql (2.58ms)4992026/10/01 07:36:37 OK 20260905000000_add_claims.sql (2.48ms)5002026/10/01 07:36:37 OK 20260920000000_drop_claims.sql (2.04ms)5012026/10/01 07:36:37 OK 20260923120000_add_pushes.sql (1.42ms)5022026/10/01 07:36:37 goose: successfully migrated database to version: 202609231200005032026/10/01 07:36:37 OK 1_commit_pending_closure.sql (1.72ms)5042026/10/01 07:36:37 OK 2_object_stats_trigger.sql (685.61µs)5052026/10/01 07:36:37 OK 3_commit_push.sql (672.47µs)5062026/10/01 07:36:37 goose: up to current file version: 3507--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.11s)508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestGCTaskStore_StartNew525=== PAUSE TestGCTaskStore_StartNew526=== RUN TestGCTaskStore_DeduplicateSameParams527=== PAUSE TestGCTaskStore_DeduplicateSameParams528=== RUN TestGCTaskStore_ConflictDifferentParams529=== PAUSE TestGCTaskStore_ConflictDifferentParams530=== RUN TestGCTaskStore_GetEmpty531=== PAUSE TestGCTaskStore_GetEmpty532=== RUN TestGCTaskStore_GetReturnsLatest533=== PAUSE TestGCTaskStore_GetReturnsLatest534=== RUN TestGCTaskStore_CompletedAllowsNewTask535=== PAUSE TestGCTaskStore_CompletedAllowsNewTask536=== RUN TestGCTaskStore_PhaseUpdates537=== PAUSE TestGCTaskStore_PhaseUpdates538=== RUN TestGCTaskStore_Fail539=== PAUSE TestGCTaskStore_Fail540=== RUN TestGracefulShutdownDrainsInflight541=== PAUSE TestGracefulShutdownDrainsInflight542=== RUN TestService_healthCheckHandler543=== PAUSE TestService_healthCheckHandler544=== RUN TestService_readinessHandler545=== PAUSE TestService_readinessHandler546=== RUN TestGenerateLandingPage547=== PAUSE TestGenerateLandingPage548=== RUN TestCacheConfigHandlerMaxNarSize549=== PAUSE TestCacheConfigHandlerMaxNarSize550=== RUN TestCreatePendingClosureRejectsOversizedNAR551=== PAUSE TestCreatePendingClosureRejectsOversizedNAR552=== RUN TestNARDeduplicationMetadataUploadBug553=== PAUSE TestNARDeduplicationMetadataUploadBug554=== RUN TestMetricsInventory555=== PAUSE TestMetricsInventory556=== RUN TestService_NativeMTLS557=== PAUSE TestService_NativeMTLS558=== RUN TestServerTLSConfig559=== PAUSE TestServerTLSConfig560=== RUN TestMultipartCleanup561=== PAUSE TestMultipartCleanup562=== RUN TestObjectStatsTrigger563=== PAUSE TestObjectStatsTrigger564=== RUN TestOrphanedObjectsGC565=== PAUSE TestOrphanedObjectsGC566=== RUN TestOrphanedObjectsGCStressTest567=== PAUSE TestOrphanedObjectsGCStressTest568=== RUN TestResurrectedObjectNotDeleted569=== PAUSE TestResurrectedObjectNotDeleted570=== RUN TestCreatePin_ReservedPins571=== PAUSE TestCreatePin_ReservedPins572=== RUN TestParseSingleRange573=== PAUSE TestParseSingleRange574=== RUN TestProxyHeadersOnlyTrustedOnSocket575=== PAUSE TestProxyHeadersOnlyTrustedOnSocket576=== RUN TestIsValidCachePath577=== PAUSE TestIsValidCachePath578=== RUN TestReadProxyNarinfo579=== PAUSE TestReadProxyNarinfo580=== RUN TestReadProxyNarinfoAlreadyDecompressed581=== PAUSE TestReadProxyNarinfoAlreadyDecompressed582=== RUN TestReadProxyNarStreaming583=== PAUSE TestReadProxyNarStreaming584=== RUN TestReadProxy404585=== PAUSE TestReadProxy404586=== RUN TestReadProxyInvalidPath587=== PAUSE TestReadProxyInvalidPath588=== RUN TestReadProxyHead589=== PAUSE TestReadProxyHead590=== RUN TestReadProxyConditionalGet591=== PAUSE TestReadProxyConditionalGet592=== RUN TestReadProxyRootRedirectsToIndexHTML593=== PAUSE TestReadProxyRootRedirectsToIndexHTML594=== RUN TestReadProxyDisabled595=== PAUSE TestReadProxyDisabled596=== RUN TestReadRedirectNar597=== PAUSE TestReadRedirectNar598=== RUN TestReadRedirectKeepsNarinfoProxied599=== PAUSE TestReadRedirectKeepsNarinfoProxied600=== RUN TestReadProxyRangeRequest601=== PAUSE TestReadProxyRangeRequest602=== RUN TestReadRedirectUsesPublicS3URL603=== PAUSE TestReadRedirectUsesPublicS3URL604=== RUN TestPush_OverlappingRootsStoreOneRowPerKey605=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey606=== RUN TestPush_CompleteCommitsEveryRoot607=== PAUSE TestPush_CompleteCommitsEveryRoot608=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit609=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit610=== RUN TestPush_RejectsBadRequests611=== PAUSE TestPush_RejectsBadRequests612=== RUN TestPush_SignsNarinfosOfItsPendingObjects613=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects614=== RUN TestRedundantMultipartUpload615=== PAUSE TestRedundantMultipartUpload616=== RUN TestCompleteMultipartUpload_ErrorButObjectExists617=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists618=== RUN TestCompletedNarNotReofferedAcrossClosures619=== PAUSE TestCompletedNarNotReofferedAcrossClosures620=== RUN TestPresignedUploadRegisteredBeforeCommit621=== PAUSE TestPresignedUploadRegisteredBeforeCommit622=== RUN TestService_Rustfstest623=== PAUSE TestService_Rustfstest624=== RUN TestParseSize625=== PAUSE TestParseSize626=== RUN TestSkippedUploadsHandler627=== PAUSE TestSkippedUploadsHandler628=== RUN TestSystemdListenerNotActivated629--- PASS: TestSystemdListenerNotActivated (0.00s)630=== RUN TestWatchdogBeatsWhenHealthy631--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)632=== RUN TestWatchdogSkipsWhenUnhealthy6332026/10/01 07:36:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6342026/10/01 07:36:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6352026/10/01 07:36:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6362026/10/01 07:36:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6372026/10/01 07:36:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6382026/10/01 07:36:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6392026/10/01 07:36:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6402026/10/01 07:36:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6412026/10/01 07:36:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6422026/10/01 07:36:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"643--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)644=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle645=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle646=== RUN TestProxyWriteTimeout647=== PAUSE TestProxyWriteTimeout648=== RUN TestIsValidUploadKey649=== PAUSE TestIsValidUploadKey650=== RUN TestUploadHandlersRejectInvalidKeys651=== PAUSE TestUploadHandlersRejectInvalidKeys652=== RUN TestUploadHandlersRejectOversizedBody653=== PAUSE TestUploadHandlersRejectOversizedBody654=== RUN TestService_cleanupPendingClosuresHandler655=== PAUSE TestService_cleanupPendingClosuresHandler656=== RUN TestService_createPendingClosureHandler657=== PAUSE TestService_createPendingClosureHandler658=== RUN TestService_verifyS3Integrity659=== PAUSE TestService_verifyS3Integrity660=== RUN TestCompleteMultipartUnregistered661=== PAUSE TestCompleteMultipartUnregistered662=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT663=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT664=== CONT TestSkippedUploadsHandler665=== CONT TestParseSize666=== CONT TestGenerateLandingPage667=== CONT TestLeadEndsOnShutdown6682026/10/01 07:36:37 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000669=== CONT TestService_readinessHandler670=== CONT TestService_healthCheckHandler671=== CONT TestGracefulShutdownDrainsInflight672=== CONT TestGCTaskStore_Fail673=== CONT TestTombstonedObjectOfferedWithoutWaiting674=== CONT TestGCTaskStore_PhaseUpdates675=== CONT TestService_AuthMiddleware_OIDC676--- PASS: TestParseSize (0.00s)677=== CONT TestGCTaskStore_CompletedAllowsNewTask678=== CONT TestGCTaskStore_GetReturnsLatest679=== CONT TestLeadElectsOneAndHandsOver680=== CONT TestGCTaskStore_GetEmpty681=== CONT TestResolveDBConnectionString682=== CONT TestGCTaskStore_ConflictDifferentParams683=== CONT TestClientFallsBackToClosures684=== CONT TestGCTaskStore_DeduplicateSameParams685=== CONT TestClientPushesUseOnePush686=== CONT TestGCTaskStore_StartNew687=== CONT TestCacheConfigHandler688=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection689=== CONT TestService_ReadScope_PublicByDefault690=== CONT TestGCSweepDeliversEachKeyOnce6912026/10/01 07:36:37 INFO Starting HTTP server address=127.0.0.1:44757692=== CONT TestService_RequireScope_OIDC693=== CONT TestService_AuthMiddleware694=== CONT TestGCSweepSkipsPendingObjects695=== CONT TestService_ReadAuthMiddleware696=== CONT TestDeduplicatedObjectsRecordedAsPending6972026/10/01 07:36:37 INFO Shutdown signal received, draining in-flight requests timeout=10s698=== CONT TestService_AuthMiddleware_MTLSBoundSubjects699=== RUN TestResolveDBConnectionString/flag_wins700=== PAUSE TestResolveDBConnectionString/flag_wins701--- PASS: TestGCTaskStore_Fail (0.00s)702--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)703=== CONT TestCacheStatsHandler704--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)705--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)706=== RUN TestCacheConfigHandler/full_config,_no_issuer707=== CONT TestPushDedupSurvivesConcurrentGC708--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)709--- PASS: TestGCTaskStore_StartNew (0.00s)710--- PASS: TestGCTaskStore_GetEmpty (0.00s)711=== RUN TestResolveDBConnectionString/file_when_flag_empty712=== PAUSE TestCacheConfigHandler/full_config,_no_issuer713=== RUN TestCacheConfigHandler/no_cache_url_configured714=== PAUSE TestCacheConfigHandler/no_cache_url_configured715=== RUN TestCacheConfigHandler/no_signing_keys716=== PAUSE TestCacheConfigHandler/no_signing_keys717=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator718=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator719--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)720=== PAUSE TestResolveDBConnectionString/file_when_flag_empty721=== RUN TestResolveDBConnectionString/missing_file_is_an_error722=== CONT TestGCMetrics723=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error724=== RUN TestResolveDBConnectionString/PGHOST_allows_empty725=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty726=== RUN TestResolveDBConnectionString/nothing_configured727=== PAUSE TestResolveDBConnectionString/nothing_configured728=== CONT TestPinProtectsFromGC729--- PASS: TestGenerateLandingPage (0.01s)730=== CONT TestGCBugBareHashReferences731--- PASS: TestSkippedUploadsHandler (0.01s)732=== CONT TestClientSharedPathCommittedMidPush7332026/10/01 07:36:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43811/oidc734--- PASS: TestGracefulShutdownDrainsInflight (0.07s)735=== CONT TestService_AuthMiddleware_MTLSProxyHeader7362026/10/01 07:36:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42461/oidc7372026-10-01 07:36:37.938 UTC [452] ERROR: relation "goose_db_version" does not exist at character 367382026-10-01 07:36:37.938 UTC [452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7392026-10-01 07:36:37.942 UTC [453] ERROR: relation "goose_db_version" does not exist at character 367402026-10-01 07:36:37.942 UTC [453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7412026-10-01 07:36:37.962 UTC [454] ERROR: relation "goose_db_version" does not exist at character 367422026-10-01 07:36:37.962 UTC [454] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7432026-10-01 07:36:37.965 UTC [455] ERROR: relation "goose_db_version" does not exist at character 367442026-10-01 07:36:37.965 UTC [455] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7452026-10-01 07:36:37.966 UTC [456] ERROR: relation "goose_db_version" does not exist at character 367462026-10-01 07:36:37.966 UTC [456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7472026-10-01 07:36:37.975 UTC [457] ERROR: relation "goose_db_version" does not exist at character 367482026-10-01 07:36:37.975 UTC [457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7492026-10-01 07:36:37.978 UTC [458] ERROR: relation "goose_db_version" does not exist at character 367502026-10-01 07:36:37.978 UTC [458] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7512026-10-01 07:36:37.982 UTC [459] ERROR: relation "goose_db_version" does not exist at character 367522026-10-01 07:36:37.982 UTC [459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7532026-10-01 07:36:38.001 UTC [460] ERROR: relation "goose_db_version" does not exist at character 367542026-10-01 07:36:38.001 UTC [460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7552026-10-01 07:36:38.003 UTC [461] ERROR: relation "goose_db_version" does not exist at character 367562026-10-01 07:36:38.003 UTC [461] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7572026/10/01 07:36:38 OK 20241026095416_initial_model.sql (39.77ms)7582026/10/01 07:36:38 OK 20241026095416_initial_model.sql (41.95ms)7592026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (4.93ms)7602026/10/01 07:36:38 OK 20241026095416_initial_model.sql (35.26ms)7612026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (5.28ms)7622026/10/01 07:36:38 OK 20241026095416_initial_model.sql (29.31ms)7632026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)7642026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (11.76ms)7652026/10/01 07:36:38 OK 20251218171726_add_pins.sql (13.33ms)7662026/10/01 07:36:38 OK 20241026095416_initial_model.sql (36.56ms)7672026/10/01 07:36:38 OK 20241026095416_initial_model.sql (27.6ms)7682026/10/01 07:36:38 OK 20251218171726_add_pins.sql (14.61ms)7692026/10/01 07:36:38 OK 20251218171726_add_pins.sql (11.25ms)7702026/10/01 07:36:38 OK 20241026095416_initial_model.sql (26.63ms)7712026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (4.03ms)7722026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (4.19ms)7732026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.19ms)7742026/10/01 07:36:38 OK 20241026095416_initial_model.sql (28.77ms)7752026/10/01 07:36:38 OK 20251218171726_add_pins.sql (7.83ms)7762026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (7.36ms)7772026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (7.3ms)7782026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (7.78ms)7792026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.19ms)7802026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.97ms)7812026/10/01 07:36:38 OK 20251218171726_add_pins.sql (4.89ms)7822026-10-01 07:36:38.035 UTC [464] ERROR: relation "goose_db_version" does not exist at character 367832026-10-01 07:36:38.035 UTC [464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7842026-10-01 07:36:38.036 UTC [467] ERROR: relation "goose_db_version" does not exist at character 367852026-10-01 07:36:38.036 UTC [467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026-10-01 07:36:38.036 UTC [465] ERROR: relation "goose_db_version" does not exist at character 367872026-10-01 07:36:38.036 UTC [465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7882026-10-01 07:36:38.036 UTC [466] ERROR: relation "goose_db_version" does not exist at character 367892026-10-01 07:36:38.036 UTC [466] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7902026/10/01 07:36:38 OK 20260905000000_add_claims.sql (9.4ms)7912026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (8.84ms)7922026-10-01 07:36:38.041 UTC [472] ERROR: relation "goose_db_version" does not exist at character 367932026-10-01 07:36:38.041 UTC [472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026-10-01 07:36:38.041 UTC [470] ERROR: relation "goose_db_version" does not exist at character 367952026-10-01 07:36:38.041 UTC [470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7962026-10-01 07:36:38.041 UTC [468] ERROR: relation "goose_db_version" does not exist at character 367972026-10-01 07:36:38.041 UTC [468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7982026-10-01 07:36:38.041 UTC [469] ERROR: relation "goose_db_version" does not exist at character 367992026-10-01 07:36:38.041 UTC [469] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8002026-10-01 07:36:38.041 UTC [471] ERROR: relation "goose_db_version" does not exist at character 368012026-10-01 07:36:38.041 UTC [471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8022026/10/01 07:36:38 OK 20260905000000_add_claims.sql (9.83ms)8032026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (7.64ms)8042026/10/01 07:36:38 OK 20260905000000_add_claims.sql (10.12ms)8052026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (12.09ms)8062026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (9.11ms)8072026/10/01 07:36:38 OK 20241026095416_initial_model.sql (16.78ms)8082026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (8.27ms)8092026/10/01 07:36:38 OK 20241026095416_initial_model.sql (20.18ms)8102026-10-01 07:36:38.044 UTC [473] ERROR: relation "goose_db_version" does not exist at character 368112026-10-01 07:36:38.044 UTC [473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8122026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.32ms)8132026-10-01 07:36:38.046 UTC [474] ERROR: relation "goose_db_version" does not exist at character 368142026-10-01 07:36:38.046 UTC [474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8152026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.58ms)8162026-10-01 07:36:38.046 UTC [475] ERROR: relation "goose_db_version" does not exist at character 368172026-10-01 07:36:38.046 UTC [475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8182026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.32ms)8192026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.89ms)8202026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4.47ms)8212026/10/01 07:36:38 OK 20251218171726_add_pins.sql (6.38ms)8222026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.7ms)8232026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4.52ms)8242026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.87ms)8252026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (4.05ms)8262026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200008272026/10/01 07:36:38 OK 20260905000000_add_claims.sql (6.95ms)8282026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (4.57ms)8292026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200008302026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.62ms)8312026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.26ms)8322026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.78ms)8332026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200008342026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.03ms)8352026-10-01 07:36:38.052 UTC [476] ERROR: relation "goose_db_version" does not exist at character 368362026-10-01 07:36:38.052 UTC [476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.92ms)8382026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.75ms)8392026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.79ms)8402026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.52ms)8412026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.89ms)8422026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (6.66ms)8432026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.52ms)8442026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200008452026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.61ms)8462026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200008472026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.41ms)8482026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.84ms)8492026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.93ms)8502026/10/01 07:36:38 OK 3_commit_push.sql (1.58ms)8512026/10/01 07:36:38 goose: up to current file version: 38522026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.77ms)8532026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200008542026/10/01 07:36:38 OK 20241026095416_initial_model.sql (13.19ms)8552026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.3ms)8562026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (6.12ms)8572026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.78ms)8582026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (4.64ms)8592026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200008602026/10/01 07:36:38 OK 3_commit_push.sql (2.78ms)8612026/10/01 07:36:38 goose: up to current file version: 38622026/10/01 07:36:38 OK 1_commit_pending_closure.sql (4.24ms)8632026/10/01 07:36:38 OK 20260905000000_add_claims.sql (5.23ms)8642026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (6.13ms)8652026/10/01 07:36:38 OK 3_commit_push.sql (1.89ms)8662026/10/01 07:36:38 goose: up to current file version: 38672026/10/01 07:36:38 OK 20241026095416_initial_model.sql (12.47ms)8682026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.18ms)8692026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.43ms)8702026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (4.01ms)8712026/10/01 07:36:38 OK 1_commit_pending_closure.sql (4.53ms)8722026/10/01 07:36:38 OK 3_commit_push.sql (2.56ms)8732026/10/01 07:36:38 goose: up to current file version: 38742026/10/01 07:36:38 OK 1_commit_pending_closure.sql (4.7ms)8752026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.14ms)8762026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.51ms)8772026/10/01 07:36:38 OK 20260905000000_add_claims.sql (5.49ms)8782026/10/01 07:36:38 OK 3_commit_push.sql (2.91ms)8792026/10/01 07:36:38 goose: up to current file version: 38802026-10-01 07:36:38.066 UTC [477] ERROR: relation "goose_db_version" does not exist at character 368812026-10-01 07:36:38.066 UTC [477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8822026/10/01 07:36:38 OK 20260905000000_add_claims.sql (6.46ms)8832026/10/01 07:36:38 OK 2_object_stats_trigger.sql (4.11ms)8842026/10/01 07:36:38 OK 20241026095416_initial_model.sql (17.15ms)8852026/10/01 07:36:38 OK 2_object_stats_trigger.sql (3.09ms)8862026/10/01 07:36:38 OK 20241026095416_initial_model.sql (15.61ms)8872026/10/01 07:36:38 OK 20241026095416_initial_model.sql (15.19ms)8882026/10/01 07:36:38 OK 20241026095416_initial_model.sql (16.8ms)8892026/10/01 07:36:38 OK 20241026095416_initial_model.sql (16.1ms)8902026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.86ms)8912026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (4.2ms)8922026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200008932026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.12ms)8942026/10/01 07:36:38 OK 20241026095416_initial_model.sql (16.47ms)8952026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.94ms)8962026/10/01 07:36:38 OK 3_commit_push.sql (2.11ms)8972026/10/01 07:36:38 goose: up to current file version: 38982026/10/01 07:36:38 OK 3_commit_push.sql (2.31ms)8992026/10/01 07:36:38 goose: up to current file version: 39002026/10/01 07:36:38 OK 20251218171726_add_pins.sql (6.18ms)9012026/10/01 07:36:38 OK 20241026095416_initial_model.sql (16.06ms)9022026/10/01 07:36:38 OK 20241026095416_initial_model.sql (18.31ms)9032026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.34ms)9042026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.24ms)9052026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.71ms)9062026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.34ms)9072026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.42ms)9082026/10/01 07:36:38 OK 20241026095416_initial_model.sql (15.99ms)9092026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.81ms)9102026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)9112026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.35ms)9122026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200009132026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (4.13ms)9142026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200009152026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)9162026/10/01 07:36:38 OK 2_object_stats_trigger.sql (3.05ms)9172026/10/01 07:36:38 OK 20241026095416_initial_model.sql (13.5ms)9182026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (4.28ms)9192026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.43ms)9202026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (4.31ms)9212026/10/01 07:36:38 OK 20241026095416_initial_model.sql (21.07ms)9222026/10/01 07:36:38 OK 20251218171726_add_pins.sql (4.81ms)9232026/10/01 07:36:38 OK 1_commit_pending_closure.sql (4.6ms)9242026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.82ms)9252026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.64ms)9262026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.71ms)9272026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.77ms)9282026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (6.56ms)9292026/10/01 07:36:38 OK 1_commit_pending_closure.sql (5.48ms)9302026/10/01 07:36:38 OK 20260905000000_add_claims.sql (5.47ms)9312026/10/01 07:36:38 OK 3_commit_push.sql (4.72ms)9322026/10/01 07:36:38 goose: up to current file version: 39332026/10/01 07:36:38 OK 20251218171726_add_pins.sql (7.17ms)9342026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (4.74ms)9352026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.99ms)9362026/10/01 07:36:38 OK 2_object_stats_trigger.sql (3.57ms)9372026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.56ms)9382026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.42ms)9392026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.38ms)9402026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.93ms)9412026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.41ms)9422026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.78ms)9432026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)9442026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)9452026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.34ms)9462026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)9472026/10/01 07:36:38 OK 3_commit_push.sql (2.98ms)9482026/10/01 07:36:38 goose: up to current file version: 39492026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.27ms)9502026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.22ms)9512026/10/01 07:36:38 OK 3_commit_push.sql (2.75ms)9522026/10/01 07:36:38 goose: up to current file version: 3953--- PASS: TestService_ReadAuthMiddleware (0.34s)954=== CONT TestClientIntegration9552026/10/01 07:36:38 OK 20251218171726_add_pins.sql (6.22ms)9562026/10/01 07:36:38 OK 20251218171726_add_pins.sql (6.23ms)9572026/10/01 07:36:38 OK 20241026095416_initial_model.sql (12.76ms)9582026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.41ms)9592026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.39ms)9602026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (6.81ms)9612026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (6.58ms)9622026/10/01 07:36:38 OK 20260905000000_add_claims.sql (6.21ms)9632026/10/01 07:36:38 OK 20260905000000_add_claims.sql (5.03ms)9642026/10/01 07:36:38 OK 20260905000000_add_claims.sql (5.29ms)9652026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.21ms)9662026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200009672026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (4.52ms)9682026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200009692026/10/01 07:36:38 OK 20260905000000_add_claims.sql (6.26ms)9702026/10/01 07:36:38 OK 20260905000000_add_claims.sql (6.31ms)9712026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)9722026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.8ms)9732026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.66ms)9742026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.82ms)9752026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.95ms)9762026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.43ms)9772026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.57ms)9782026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.46ms)9792026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.52ms)9802026/10/01 07:36:38 OK 20260905000000_add_claims.sql (5.63ms)9812026/10/01 07:36:38 OK 20260905000000_add_claims.sql (6.03ms)9822026/10/01 07:36:38 OK 20260905000000_add_claims.sql (7.42ms)9832026/10/01 07:36:38 OK 20260905000000_add_claims.sql (6.31ms)9842026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.78ms)9852026/10/01 07:36:38 OK 2_object_stats_trigger.sql (3.04ms)9862026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (9.71ms)9872026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.94ms)9882026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200009892026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (4.36ms)9902026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200009912026/10/01 07:36:38 OK 3_commit_push.sql (1.44ms)9922026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (4.29ms)9932026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200009942026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.75ms)9952026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.95ms)9962026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200009972026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4.63ms)9982026/10/01 07:36:38 goose: up to current file version: 39992026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.18ms)10002026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.25ms)10012026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (4.11ms)10022026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000010032026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (5.87ms)10042026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.09ms)10052026/10/01 07:36:38 OK 3_commit_push.sql (1.82ms)10062026/10/01 07:36:38 goose: up to current file version: 310072026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.16ms)10082026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.81ms)10092026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.83ms)10102026/10/01 07:36:38 OK 20260905000000_add_claims.sql (5.42ms)10112026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.55ms)10122026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.2ms)10132026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000010142026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.37ms)10152026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000010162026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.66ms)10172026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.33ms)10182026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (4.26ms)10192026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.58ms)10202026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000010212026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.75ms)10222026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.83ms)10232026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000010242026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.31ms)10252026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.74ms)10262026/10/01 07:36:38 OK 3_commit_push.sql (3.1ms)10272026/10/01 07:36:38 goose: up to current file version: 310282026/10/01 07:36:38 OK 2_object_stats_trigger.sql (3.93ms)10292026/10/01 07:36:38 OK 3_commit_push.sql (3.75ms)10302026/10/01 07:36:38 goose: up to current file version: 310312026/10/01 07:36:38 OK 1_commit_pending_closure.sql (4.37ms)10322026/10/01 07:36:38 OK 2_object_stats_trigger.sql (5.13ms)10332026/10/01 07:36:38 OK 1_commit_pending_closure.sql (4.64ms)10342026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (5.39ms)10352026/10/01 07:36:38 OK 1_commit_pending_closure.sql (4.48ms)10362026/10/01 07:36:38 OK 3_commit_push.sql (3.51ms)10372026/10/01 07:36:38 goose: up to current file version: 310382026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (4.68ms)10392026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000010402026/10/01 07:36:38 OK 1_commit_pending_closure.sql (5.84ms)10412026/10/01 07:36:38 OK 3_commit_push.sql (1.88ms)10422026/10/01 07:36:38 goose: up to current file version: 310432026/10/01 07:36:38 OK 3_commit_push.sql (2.63ms)10442026/10/01 07:36:38 goose: up to current file version: 310452026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.49ms)10462026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.77ms)10472026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.03ms)10482026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.86ms)10492026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000010502026/10/01 07:36:38 INFO Received uploads request method=POST path=/api/pending_closures10512026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.77ms)10522026/10/01 07:36:38 OK 20260905000000_add_claims.sql (7.97ms)10532026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.77ms)10542026/10/01 07:36:38 OK 3_commit_push.sql (1.07ms)10552026/10/01 07:36:38 goose: up to current file version: 310562026/10/01 07:36:38 OK 3_commit_push.sql (1.72ms)10572026/10/01 07:36:38 goose: up to current file version: 310582026/10/01 07:36:38 OK 3_commit_push.sql (1.43ms)10592026/10/01 07:36:38 goose: up to current file version: 310602026/10/01 07:36:38 OK 3_commit_push.sql (1.52ms)10612026/10/01 07:36:38 goose: up to current file version: 310622026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.46ms)10632026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.22ms)10642026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.29ms)10652026/10/01 07:36:38 OK 3_commit_push.sql (1.24ms)10662026/10/01 07:36:38 goose: up to current file version: 310672026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.85ms)10682026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.42ms)10692026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000010702026/10/01 07:36:38 OK 3_commit_push.sql (2.17ms)10712026/10/01 07:36:38 goose: up to current file version: 31072--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.37s)1073=== CONT TestClientErrorHandling1074=== RUN TestClientErrorHandling/InvalidStorePath1075=== PAUSE TestClientErrorHandling/InvalidStorePath1076=== RUN TestClientErrorHandling/InvalidAuthToken1077=== PAUSE TestClientErrorHandling/InvalidAuthToken1078=== RUN TestClientErrorHandling/ServerNotAvailable1079=== PAUSE TestClientErrorHandling/ServerNotAvailable1080=== CONT TestClientWithDependencies10812026/10/01 07:36:38 OK 1_commit_pending_closure.sql (4.17ms)10822026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.45ms)10832026/10/01 07:36:38 OK 3_commit_push.sql (1.58ms)10842026/10/01 07:36:38 goose: up to current file version: 310852026/10/01 07:36:38 WARN readiness check failed error="closed pool"1086--- PASS: TestService_readinessHandler (0.38s)1087=== CONT TestClientCADerivations10882026/10/01 07:36:38 INFO Received uploads request method=POST path=/api/pending_closures10892026-10-01 07:36:38.173 UTC [485] ERROR: relation "goose_db_version" does not exist at character 3610902026-10-01 07:36:38.173 UTC [485] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1091--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.43s)1092=== CONT TestClientMultipleUploads10932026/10/01 07:36:38 OK 20241026095416_initial_model.sql (14.3ms)10942026/10/01 07:36:38 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1095--- PASS: TestService_AuthMiddleware (0.45s)1096=== CONT TestReadProxyInvalidPath10972026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.53ms)10982026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.79ms)10992026-10-01 07:36:38.204 UTC [489] ERROR: relation "goose_db_version" does not exist at character 3611002026-10-01 07:36:38.204 UTC [489] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11012026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)11022026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4.29ms)11032026-10-01 07:36:38.212 UTC [491] ERROR: relation "goose_db_version" does not exist at character 3611042026-10-01 07:36:38.212 UTC [491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11052026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.13ms)11062026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.14ms)11072026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000011082026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.69ms)11092026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10.33ms)11102026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.92ms)11112026/10/01 07:36:38 INFO lead: acquired remote=192.0.2.1:123411122026/10/01 07:36:38 INFO lead: released remote=192.0.2.1:12341113--- PASS: TestLeadEndsOnShutdown (0.48s)1114=== CONT TestOrphanedObjectsGCStressTest11152026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)11162026/10/01 07:36:38 OK 3_commit_push.sql (1.53ms)11172026/10/01 07:36:38 goose: up to current file version: 311182026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.84ms)11192026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10ms)11202026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)11212026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)11222026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4.19ms)11232026/10/01 07:36:38 OK 20251218171726_add_pins.sql (4.62ms)11242026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.6ms)11252026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.97ms)11262026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.57ms)11272026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000011282026/10/01 07:36:38 INFO lead: acquired remote=192.0.2.1:123411292026-10-01 07:36:38.247 UTC [494] ERROR: relation "goose_db_version" does not exist at character 3611302026-10-01 07:36:38.247 UTC [494] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11312026/10/01 07:36:38 OK 1_commit_pending_closure.sql (9.15ms)11322026/10/01 07:36:38 OK 20260905000000_add_claims.sql (11.35ms)11332026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.17ms)11342026/10/01 07:36:38 OK 3_commit_push.sql (1.76ms)11352026/10/01 07:36:38 goose: up to current file version: 311362026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.78ms)11372026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.85ms)11382026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000011392026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.26ms)11402026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.42ms)11412026/10/01 07:36:38 OK 3_commit_push.sql (1.1ms)11422026/10/01 07:36:38 goose: up to current file version: 311432026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10.02ms)11442026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)1145--- PASS: TestService_healthCheckHandler (0.52s)1146=== CONT TestService_cleanupPendingClosuresHandler11472026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.3ms)11482026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (2.98ms)11492026-10-01 07:36:38.273 UTC [497] ERROR: relation "goose_db_version" does not exist at character 3611502026-10-01 07:36:38.273 UTC [497] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11512026/10/01 07:36:38 OK 20260905000000_add_claims.sql (2.81ms)11522026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.47ms)11532026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (1.9ms)11542026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000011552026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.11ms)11562026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.52ms)11572026/10/01 07:36:38 OK 3_commit_push.sql (1.44ms)11582026/10/01 07:36:38 goose: up to current file version: 311592026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10.49ms)11602026-10-01 07:36:38.289 UTC [499] ERROR: relation "goose_db_version" does not exist at character 3611612026-10-01 07:36:38.289 UTC [499] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11622026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)11632026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.23ms)11642026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.43ms)11652026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.9ms)11662026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10.38ms)11672026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.15ms)11682026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)11692026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.68ms)11702026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000011712026/10/01 07:36:38 OK 20251218171726_add_pins.sql (4ms)11722026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.36ms)11732026/10/01 07:36:38 INFO Received uploads request method=POST path=/api/pending_closures11742026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.56ms)11752026/10/01 07:36:38 OK 3_commit_push.sql (1.23ms)11762026/10/01 07:36:38 goose: up to current file version: 311772026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)11782026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4.15ms)11792026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.56ms)11802026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.4ms)11812026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000011822026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.08ms)11832026/10/01 07:36:38 OK 2_object_stats_trigger.sql (941.23µs)11842026/10/01 07:36:38 OK 3_commit_push.sql (1.7ms)11852026/10/01 07:36:38 goose: up to current file version: 311862026/10/01 07:36:38 INFO Aborted multipart uploads count=011872026/10/01 07:36:38 WARN Force mode enabled - objects will be deleted immediately without grace period11882026-10-01 07:36:38.338 UTC [519] ERROR: relation "goose_db_version" does not exist at character 3611892026-10-01 07:36:38.338 UTC [519] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11902026/10/01 07:36:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011912026/10/01 07:36:38 INFO Vacuumed table table=pending_closures11922026/10/01 07:36:38 INFO Vacuumed table table=pending_objects11932026/10/01 07:36:38 INFO Vacuumed table table=multipart_uploads11942026/10/01 07:36:38 INFO Vacuumed table table=closures11952026/10/01 07:36:38 INFO Vacuumed table table=objects11962026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10.24ms)1197--- PASS: TestGCSweepSkipsPendingObjects (0.61s)1198=== CONT TestService_Rustfstest11992026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)12002026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.35ms)12012026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (6.54ms)12022026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.46ms)12032026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.55ms)12042026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.03ms)12052026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000012062026/10/01 07:36:38 OK 1_commit_pending_closure.sql (1.81ms)12072026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.64ms)12082026/10/01 07:36:38 OK 3_commit_push.sql (1.74ms)12092026/10/01 07:36:38 goose: up to current file version: 312102026/10/01 07:36:38 INFO lead: released remote=192.0.2.1:123412112026/10/01 07:36:38 INFO Aborted multipart uploads count=012122026/10/01 07:36:38 WARN Force mode enabled - objects will be deleted immediately without grace period12132026-10-01 07:36:38.437 UTC [593] ERROR: relation "goose_db_version" does not exist at character 3612142026-10-01 07:36:38.437 UTC [593] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12152026/10/01 07:36:38 INFO lead: acquired remote=192.0.2.1:123412162026/10/01 07:36:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=012172026/10/01 07:36:38 INFO Vacuumed table table=pending_closures12182026/10/01 07:36:38 INFO Vacuumed table table=pending_objects12192026/10/01 07:36:38 INFO lead: released remote=192.0.2.1:12341220--- PASS: TestLeadElectsOneAndHandsOver (0.71s)1221=== CONT TestReadProxy40412222026/10/01 07:36:38 INFO Vacuumed table table=multipart_uploads12232026/10/01 07:36:38 INFO Vacuumed table table=closures12242026/10/01 07:36:38 INFO Vacuumed table table=objects1225--- PASS: TestGCSweepDeliversEachKeyOnce (0.71s)1226=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT12272026/10/01 07:36:38 OK 20241026095416_initial_model.sql (11.24ms)12282026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)12292026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.44ms)12302026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (3.77ms)12312026/10/01 07:36:38 OK 20260905000000_add_claims.sql (11.27ms)12322026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.34ms)12332026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.8ms)12342026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000012352026/10/01 07:36:38 INFO Received uploads request method=POST path=/api/pending_closures12362026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.09ms)12372026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.57ms)12382026/10/01 07:36:38 OK 3_commit_push.sql (1.25ms)12392026/10/01 07:36:38 goose: up to current file version: 312402026/10/01 07:36:38 INFO Received uploads request method=POST path=/api/pending_closures12412026/10/01 07:36:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12422026/10/01 07:36:38 INFO Uploading lm9rx9is0wk1bhxi465blcb3vkwpyc8x-b (216B)12432026/10/01 07:36:38 INFO Uploading si40ggw5i9ap986qpdl4qhkgn7r5rz5l-shared-dep (136B)12442026/10/01 07:36:38 INFO Received uploads request method=POST path=/api/pending_closures12452026/10/01 07:36:38 WARN Failed to register uploaded object key=zdyd9wf1822wkbvgx26g3asjwif11nhg.ls error="server returned 404: 404 page not found\n"12462026/10/01 07:36:38 WARN Failed to register uploaded object key=nar/01gsapvhlf6hd0cmyk2wqkg62wki6nyd4yhrqvxb1kv3zw3hjgpi.nar.zst error="server returned 404: 404 page not found\n"12472026/10/01 07:36:38 WARN Failed to register uploaded object key=si40ggw5i9ap986qpdl4qhkgn7r5rz5l.ls error="server returned 404: 404 page not found\n"12482026/10/01 07:36:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12492026/10/01 07:36:38 WARN Failed to register uploaded object key=lm9rx9is0wk1bhxi465blcb3vkwpyc8x.ls error="server returned 404: 404 page not found\n"12502026/10/01 07:36:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12512026/10/01 07:36:38 INFO Signed narinfos id=1 count=212522026/10/01 07:36:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1253--- PASS: TestCacheStatsHandler (0.76s)12542026/10/01 07:36:38 INFO Signed narinfos id=2 count=21255=== CONT TestPresignedUploadRegisteredBeforeCommit12562026/10/01 07:36:38 INFO Uploading 4 narinfos12572026/10/01 07:36:38 WARN Failed to register uploaded object key=si40ggw5i9ap986qpdl4qhkgn7r5rz5l.narinfo error="server returned 404: 404 page not found\n"12582026/10/01 07:36:38 WARN Failed to register uploaded object key=zdyd9wf1822wkbvgx26g3asjwif11nhg.narinfo error="server returned 404: 404 page not found\n"12592026/10/01 07:36:38 WARN Failed to register uploaded object key=lm9rx9is0wk1bhxi465blcb3vkwpyc8x.narinfo error="server returned 404: 404 page not found\n"12602026/10/01 07:36:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12612026/10/01 07:36:38 WARN Failed to register uploaded object key=si40ggw5i9ap986qpdl4qhkgn7r5rz5l.narinfo error="server returned 404: 404 page not found\n"12622026/10/01 07:36:38 INFO Completed upload id=112632026/10/01 07:36:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12642026/10/01 07:36:38 INFO Completed upload id=212652026/10/01 07:36:38 INFO Upload complete. (68ms)12662026/10/01 07:36:38 INFO Received push request method=POST path=/api/pushes1267=== NAME TestClientFallsBackToClosures1268 client_pushes_test.go:112: Retrieved narinfo from S3:1269 StorePath: /build/TestClientFallsBackToClosures1137844656/001/store/si40ggw5i9ap986qpdl4qhkgn7r5rz5l-shared-dep1270 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1271 Compression: zstd1272 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821273 NarSize: 1361274 References: 1275 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12762026/10/01 07:36:38 INFO Aborted multipart uploads count=012772026-10-01 07:36:38.524 UTC [709] ERROR: relation "goose_db_version" does not exist at character 3612782026-10-01 07:36:38.524 UTC [709] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12792026-10-01 07:36:38.524 UTC [710] ERROR: relation "goose_db_version" does not exist at character 3612802026-10-01 07:36:38.524 UTC [710] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1281 client_pushes_test.go:112: Retrieved narinfo from S3:1282 StorePath: /build/TestClientFallsBackToClosures1137844656/001/store/zdyd9wf1822wkbvgx26g3asjwif11nhg-a1283 URL: nar/01gsapvhlf6hd0cmyk2wqkg62wki6nyd4yhrqvxb1kv3zw3hjgpi.nar.zst1284 Compression: zstd1285 NarHash: sha256:01gsapvhlf6hd0cmyk2wqkg62wki6nyd4yhrqvxb1kv3zw3hjgpi1286 NarSize: 2161287 References: /build/TestClientFallsBackToClosures1137844656/001/store/si40ggw5i9ap986qpdl4qhkgn7r5rz5l-shared-dep1288 CA: text:sha256:09aflw28hndx3714ks0b580lyi49pmc7j08mrvdc3y7gfvjwl5ls12892026/10/01 07:36:38 WARN Force mode enabled - objects will be deleted immediately without grace period12902026/10/01 07:36:38 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12912026/10/01 07:36:38 INFO Uploading hxmbdbbf9s1pr4qq9gd92q9jarlr8aw8-shared-dep (136B)12922026/10/01 07:36:38 INFO Uploading gr9hxfwn0rf7jmikjxscl3p173fv650h-top (224B)1293 client_pushes_test.go:112: Retrieved narinfo from S3:1294 StorePath: /build/TestClientFallsBackToClosures1137844656/001/store/lm9rx9is0wk1bhxi465blcb3vkwpyc8x-b1295 URL: nar/01gsapvhlf6hd0cmyk2wqkg62wki6nyd4yhrqvxb1kv3zw3hjgpi.nar.zst1296 Compression: zstd1297 NarHash: sha256:01gsapvhlf6hd0cmyk2wqkg62wki6nyd4yhrqvxb1kv3zw3hjgpi12982026/10/01 07:36:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01299 NarSize: 2161300 References: /build/TestClientFallsBackToClosures1137844656/001/store/si40ggw5i9ap986qpdl4qhkgn7r5rz5l-shared-dep1301 CA: text:sha256:09aflw28hndx3714ks0b580lyi49pmc7j08mrvdc3y7gfvjwl5ls13022026/10/01 07:36:38 INFO Vacuumed table table=pending_closures13032026/10/01 07:36:38 INFO Vacuumed table table=pending_objects13042026/10/01 07:36:38 INFO Vacuumed table table=multipart_uploads13052026/10/01 07:36:38 INFO Vacuumed table table=closures13062026/10/01 07:36:38 INFO Vacuumed table table=objects13072026/10/01 07:36:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13082026/10/01 07:36:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13092026/10/01 07:36:38 WARN Failed to register uploaded object key=hxmbdbbf9s1pr4qq9gd92q9jarlr8aw8.ls error="server returned 404: 404 page not found\n"13102026/10/01 07:36:38 WARN Failed to register uploaded object key=gr9hxfwn0rf7jmikjxscl3p173fv650h.ls error="server returned 404: 404 page not found\n"13112026/10/01 07:36:38 WARN Failed to register uploaded object key=nar/05mv49p89cn1czi0jrgvi0bn91vbvw9r55d91qzgdf7m5h4adklp.nar.zst error="server returned 404: 404 page not found\n"1312--- PASS: TestClientFallsBackToClosures (0.79s)1313=== CONT TestReadProxyNarStreaming13142026/10/01 07:36:38 INFO Signed narinfos id=1 count=213152026/10/01 07:36:38 INFO Uploading 2 narinfos1316--- PASS: TestService_ReadScope_PublicByDefault (0.79s)1317=== CONT TestCompletedNarNotReofferedAcrossClosures1318--- PASS: TestGCMetrics (0.79s)1319=== CONT TestReadProxyNarinfoAlreadyDecompressed13202026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10.1ms)13212026/10/01 07:36:38 INFO Received complete push request method=POST path=/api/pushes/1/complete13222026/10/01 07:36:38 WARN Failed to register uploaded object key=gr9hxfwn0rf7jmikjxscl3p173fv650h.narinfo error="server returned 404: 404 page not found\n"13232026/10/01 07:36:38 WARN Failed to register uploaded object key=hxmbdbbf9s1pr4qq9gd92q9jarlr8aw8.narinfo error="server returned 404: 404 page not found\n"13242026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10.88ms)13252026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)13262026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (1.81ms)13272026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.78ms)13282026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.51ms)13292026/10/01 07:36:38 INFO Upload complete. (68ms)1330=== NAME TestClientSharedPathCommittedMidPush1331 client_integration_test.go:680: Retrieved narinfo from S3:1332 StorePath: /build/TestClientSharedPathCommittedMidPush4166123877/001/store/hxmbdbbf9s1pr4qq9gd92q9jarlr8aw8-shared-dep1333 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1334 Compression: zstd1335 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821336 NarSize: 1361337 References: 1338 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13392026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.33ms)13402026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.46ms)1341--- PASS: TestGCBugBareHashReferences (0.81s)1342=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1343=== NAME TestClientSharedPathCommittedMidPush1344 client_integration_test.go:680: Retrieved narinfo from S3:1345 StorePath: /build/TestClientSharedPathCommittedMidPush4166123877/001/store/gr9hxfwn0rf7jmikjxscl3p173fv650h-top1346 URL: nar/05mv49p89cn1czi0jrgvi0bn91vbvw9r55d91qzgdf7m5h4adklp.nar.zst13472026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.96ms)1348 Compression: zstd1349 NarHash: sha256:05mv49p89cn1czi0jrgvi0bn91vbvw9r55d91qzgdf7m5h4adklp1350 NarSize: 2241351 References: /build/TestClientSharedPathCommittedMidPush4166123877/001/store/hxmbdbbf9s1pr4qq9gd92q9jarlr8aw8-shared-dep1352 CA: text:sha256:0iwfwnnzpxqdsq7nhydp7pajbr0vi171npsa63sl0l55f1y1yip513532026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4.15ms)13542026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.2ms)13552026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.89ms)1356--- PASS: TestClientSharedPathCommittedMidPush (0.81s)1357=== CONT TestReadProxyNarinfo13582026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.66ms)13592026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000013602026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.97ms)13612026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000013622026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.4ms)13632026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.27ms)13642026/10/01 07:36:38 INFO Aborted multipart uploads count=013652026/10/01 07:36:38 OK 2_object_stats_trigger.sql (8.2ms)13662026/10/01 07:36:38 OK 2_object_stats_trigger.sql (8.27ms)13672026/10/01 07:36:38 OK 3_commit_push.sql (2.57ms)13682026/10/01 07:36:38 goose: up to current file version: 313692026/10/01 07:36:38 OK 3_commit_push.sql (1.76ms)13702026/10/01 07:36:38 goose: up to current file version: 313712026/10/01 07:36:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01372=== RUN TestService_RequireScope_OIDC/builder_may_write1373=== PAUSE TestService_RequireScope_OIDC/builder_may_write1374=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1375=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1376=== RUN TestService_RequireScope_OIDC/ops_may_admin1377=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1378=== RUN TestService_RequireScope_OIDC/ops_may_not_write1379=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1380=== RUN TestService_RequireScope_OIDC/reader_may_not_write1381=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1382=== RUN TestService_RequireScope_OIDC/static_token_may_admin1383=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1384=== RUN TestService_RequireScope_OIDC/static_token_may_write1385=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1386=== RUN TestService_RequireScope_OIDC/reader_may_read1387=== PAUSE TestService_RequireScope_OIDC/reader_may_read1388=== RUN TestService_RequireScope_OIDC/writer_implies_read1389=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1390=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1391=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1392=== CONT TestRedundantMultipartUpload13932026/10/01 07:36:38 INFO Vacuumed table table=pending_closures13942026-10-01 07:36:38.585 UTC [757] ERROR: relation "goose_db_version" does not exist at character 3613952026-10-01 07:36:38.585 UTC [757] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13962026/10/01 07:36:38 INFO Vacuumed table table=pending_objects13972026/10/01 07:36:38 INFO Vacuumed table table=multipart_uploads13982026/10/01 07:36:38 INFO Vacuumed table table=closures13992026/10/01 07:36:38 INFO Vacuumed table table=objects14002026/10/01 07:36:38 INFO Aborted multipart uploads count=014012026/10/01 07:36:38 WARN Force mode enabled - objects will be deleted immediately without grace period14022026/10/01 07:36:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014032026/10/01 07:36:38 INFO Vacuumed table table=pending_closures14042026/10/01 07:36:38 OK 20241026095416_initial_model.sql (13.15ms)14052026/10/01 07:36:38 INFO Received push request method=POST path=/api/pushes14062026/10/01 07:36:38 INFO Vacuumed table table=pending_objects14072026/10/01 07:36:38 INFO Vacuumed table table=multipart_uploads14082026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)14092026/10/01 07:36:38 INFO Vacuumed table table=closures14102026/10/01 07:36:38 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14112026/10/01 07:36:38 WARN mTLS auth: bound subjects configured but subject DN unavailable14122026/10/01 07:36:38 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1413--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.87s)1414=== CONT TestPush_SignsNarinfosOfItsPendingObjects14152026/10/01 07:36:38 INFO Vacuumed table table=objects14162026/10/01 07:36:38 OK 20251218171726_add_pins.sql (9.34ms)1417--- PASS: TestPushDedupSurvivesConcurrentGC (0.87s)1418=== CONT TestPush_RejectsBadRequests14192026/10/01 07:36:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14202026/10/01 07:36:38 INFO Uploading galagfid899rv7bldxldfydbx0zhvr85-shared-dep (136B)14212026/10/01 07:36:38 INFO Uploading qsxkbfqaaxia2vpmc6i118slrvwjdflm-a (216B)14222026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)14232026/10/01 07:36:38 WARN Failed to register uploaded object key=nar/1dk4k99nrq15nrfbhss6ls5g8w0sv79648b17kg0d9h2l8r2sdp9.nar.zst error="server returned 404: 404 page not found\n"14242026/10/01 07:36:38 WARN Failed to register uploaded object key=galagfid899rv7bldxldfydbx0zhvr85.ls error="server returned 404: 404 page not found\n"14252026/10/01 07:36:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14262026/10/01 07:36:38 WARN Failed to register uploaded object key=h8s1gmkplp8rnxwrz9070gjpwykpkady.ls error="server returned 404: 404 page not found\n"14272026/10/01 07:36:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14282026/10/01 07:36:38 WARN Failed to register uploaded object key=qsxkbfqaaxia2vpmc6i118slrvwjdflm.ls error="server returned 404: 404 page not found\n"14292026/10/01 07:36:38 INFO Signed narinfos id=1 count=314302026/10/01 07:36:38 INFO Uploading 3 narinfos14312026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.4ms)14322026-10-01 07:36:38.631 UTC [799] ERROR: relation "goose_db_version" does not exist at character 3614332026-10-01 07:36:38.631 UTC [799] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14342026-10-01 07:36:38.631 UTC [800] ERROR: relation "goose_db_version" does not exist at character 3614352026-10-01 07:36:38.631 UTC [800] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14362026-10-01 07:36:38.631 UTC [798] ERROR: relation "goose_db_version" does not exist at character 3614372026-10-01 07:36:38.631 UTC [798] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14382026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.23ms)14392026/10/01 07:36:38 INFO Received complete push request method=POST path=/api/pushes/1/complete14402026/10/01 07:36:38 WARN Failed to register uploaded object key=h8s1gmkplp8rnxwrz9070gjpwykpkady.narinfo error="server returned 404: 404 page not found\n"14412026/10/01 07:36:38 WARN Failed to register uploaded object key=galagfid899rv7bldxldfydbx0zhvr85.narinfo error="server returned 404: 404 page not found\n"14422026/10/01 07:36:38 WARN Failed to register uploaded object key=qsxkbfqaaxia2vpmc6i118slrvwjdflm.narinfo error="server returned 404: 404 page not found\n"14432026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.45ms)14442026/10/01 07:36:38 goose: successfully migrated database to version: 202609231200001445--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.82s)1446=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit14472026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.41ms)14482026-10-01 07:36:38.639 UTC [803] ERROR: relation "goose_db_version" does not exist at character 3614492026-10-01 07:36:38.639 UTC [803] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14502026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.23ms)14512026/10/01 07:36:38 INFO Upload complete. (69ms)14522026/10/01 07:36:38 OK 3_commit_push.sql (1.74ms)14532026/10/01 07:36:38 goose: up to current file version: 31454=== NAME TestClientPushesUseOnePush1455 client_pushes_test.go:97: Retrieved narinfo from S3:1456 StorePath: /build/TestClientPushesUseOnePush1260455356/001/store/galagfid899rv7bldxldfydbx0zhvr85-shared-dep1457 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1458 Compression: zstd1459 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821460 NarSize: 1361461 References: 1462 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14632026-10-01 07:36:38.647 UTC [805] ERROR: relation "goose_db_version" does not exist at character 3614642026-10-01 07:36:38.647 UTC [805] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1465 client_pushes_test.go:97: Retrieved narinfo from S3:1466 StorePath: /build/TestClientPushesUseOnePush1260455356/001/store/qsxkbfqaaxia2vpmc6i118slrvwjdflm-a1467 URL: nar/1dk4k99nrq15nrfbhss6ls5g8w0sv79648b17kg0d9h2l8r2sdp9.nar.zst1468 Compression: zstd1469 NarHash: sha256:1dk4k99nrq15nrfbhss6ls5g8w0sv79648b17kg0d9h2l8r2sdp91470 NarSize: 2161471 References: /build/TestClientPushesUseOnePush1260455356/001/store/galagfid899rv7bldxldfydbx0zhvr85-shared-dep1472 CA: text:sha256:1l564qf179lpgpdajvdmfjxhndwaihx1wh73aw1zsxvrn51h7kjz14732026/10/01 07:36:38 OK 20241026095416_initial_model.sql (12.46ms)14742026/10/01 07:36:38 OK 20241026095416_initial_model.sql (12.13ms)1475 client_pushes_test.go:97: Retrieved narinfo from S3:1476 StorePath: /build/TestClientPushesUseOnePush1260455356/001/store/h8s1gmkplp8rnxwrz9070gjpwykpkady-b1477 URL: nar/1dk4k99nrq15nrfbhss6ls5g8w0sv79648b17kg0d9h2l8r2sdp9.nar.zst1478 Compression: zstd1479 NarHash: sha256:1dk4k99nrq15nrfbhss6ls5g8w0sv79648b17kg0d9h2l8r2sdp91480 NarSize: 2161481 References: /build/TestClientPushesUseOnePush1260455356/001/store/galagfid899rv7bldxldfydbx0zhvr85-shared-dep1482 CA: text:sha256:1l564qf179lpgpdajvdmfjxhndwaihx1wh73aw1zsxvrn51h7kjz14832026/10/01 07:36:38 OK 20241026095416_initial_model.sql (14.85ms)14842026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.94ms)14852026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (3.71ms)1486--- PASS: TestClientPushesUseOnePush (0.91s)1487=== CONT TestIsValidCachePath1488=== RUN TestIsValidCachePath/narinfo1489=== PAUSE TestIsValidCachePath/narinfo1490=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars14912026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (4.95ms)1492=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1493=== RUN TestIsValidCachePath/nar_zst1494=== PAUSE TestIsValidCachePath/nar_zst1495=== RUN TestIsValidCachePath/nar_xz1496=== PAUSE TestIsValidCachePath/nar_xz1497=== RUN TestIsValidCachePath/nar_bz21498=== PAUSE TestIsValidCachePath/nar_bz21499=== RUN TestIsValidCachePath/nar_uncompressed1500=== PAUSE TestIsValidCachePath/nar_uncompressed1501=== RUN TestIsValidCachePath/ls1502=== PAUSE TestIsValidCachePath/ls1503=== RUN TestIsValidCachePath/log1504=== PAUSE TestIsValidCachePath/log1505=== RUN TestIsValidCachePath/realisation1506=== PAUSE TestIsValidCachePath/realisation1507=== RUN TestIsValidCachePath/nix-cache-info1508=== PAUSE TestIsValidCachePath/nix-cache-info1509=== RUN TestIsValidCachePath/index.html1510=== PAUSE TestIsValidCachePath/index.html1511=== RUN TestIsValidCachePath/traversal_parent1512=== PAUSE TestIsValidCachePath/traversal_parent1513=== RUN TestIsValidCachePath/traversal_in_middle1514=== PAUSE TestIsValidCachePath/traversal_in_middle1515=== RUN TestIsValidCachePath/invalid_char_e1516=== PAUSE TestIsValidCachePath/invalid_char_e1517=== RUN TestIsValidCachePath/invalid_char_u1518=== PAUSE TestIsValidCachePath/invalid_char_u1519=== RUN TestIsValidCachePath/random_path1520=== PAUSE TestIsValidCachePath/random_path1521=== RUN TestIsValidCachePath/empty1522=== PAUSE TestIsValidCachePath/empty1523=== RUN TestIsValidCachePath/leading_slash1524=== PAUSE TestIsValidCachePath/leading_slash1525=== RUN TestIsValidCachePath/wrong_extension1526=== PAUSE TestIsValidCachePath/wrong_extension1527=== RUN TestIsValidCachePath/short_hash15282026/10/01 07:36:38 OK 20251218171726_add_pins.sql (4.42ms)1529=== PAUSE TestIsValidCachePath/short_hash1530=== CONT TestPush_CompleteCommitsEveryRoot15312026/10/01 07:36:38 OK 20251218171726_add_pins.sql (5.13ms)15322026/10/01 07:36:38 OK 20241026095416_initial_model.sql (13.18ms)15332026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)15342026/10/01 07:36:38 OK 20251218171726_add_pins.sql (4.64ms)15352026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.84ms)15362026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5ms)15372026/10/01 07:36:38 OK 20251218171726_add_pins.sql (4.61ms)15382026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4ms)15392026/10/01 07:36:38 OK 20241026095416_initial_model.sql (12.17ms)15402026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)1541=== NAME TestPinProtectsFromGC1542 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3945341807/001/store/ag41xsx2vlyy0qhy1b55c4cz17m8x8gl-pinned-file.txt1543 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3945341807/001/store/0112dcl54kf60w5mln914f44cd9i43xc-unpinned-file.txt15442026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.92ms)15452026-10-01 07:36:38.669 UTC [824] ERROR: relation "goose_db_version" does not exist at character 3615462026-10-01 07:36:38.669 UTC [824] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15472026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.34ms)15482026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.71ms)15492026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.72ms)15502026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.04ms)15512026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)15522026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.62ms)15532026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (3.15ms)15542026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000015552026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.49ms)15562026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000015572026/10/01 07:36:38 INFO Received uploads request method=POST path=/api/pending_closures15582026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4.46ms)15592026/10/01 07:36:38 OK 1_commit_pending_closure.sql (9.15ms)15602026/10/01 07:36:38 OK 1_commit_pending_closure.sql (11.24ms)15612026/10/01 07:36:38 OK 20251218171726_add_pins.sql (13.11ms)15622026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (11.49ms)15632026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000015642026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (10.2ms)15652026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.81ms)15662026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10.79ms)15672026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.1ms)15682026/10/01 07:36:38 OK 3_commit_push.sql (2.41ms)15692026/10/01 07:36:38 goose: up to current file version: 315702026/10/01 07:36:38 OK 1_commit_pending_closure.sql (3.12ms)15712026/10/01 07:36:38 OK 3_commit_push.sql (1.41ms)15722026/10/01 07:36:38 goose: up to current file version: 315732026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.23ms)15742026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.59ms)15752026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)15762026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (5.04ms)15772026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000015782026/10/01 07:36:38 OK 3_commit_push.sql (1.02ms)15792026/10/01 07:36:38 goose: up to current file version: 315802026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.3ms)15812026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.63ms)15822026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.87ms)15832026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.57ms)15842026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.24ms)15852026/10/01 07:36:38 OK 3_commit_push.sql (1.24ms)15862026/10/01 07:36:38 goose: up to current file version: 31587=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1588=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1589=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1590=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1591=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1592=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1593=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1594=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1595=== CONT TestProxyHeadersOnlyTrustedOnSocket15962026-10-01 07:36:38.698 UTC [827] ERROR: relation "goose_db_version" does not exist at character 3615972026-10-01 07:36:38.698 UTC [827] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15982026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)15992026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (6.3ms)16002026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000016012026-10-01 07:36:38.703 UTC [845] ERROR: relation "goose_db_version" does not exist at character 3616022026-10-01 07:36:38.703 UTC [845] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16032026/10/01 07:36:38 OK 20260905000000_add_claims.sql (5.22ms)16042026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.99ms)16052026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.08ms)16062026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.24ms)16072026/10/01 07:36:38 OK 3_commit_push.sql (1.19ms)16082026/10/01 07:36:38 goose: up to current file version: 316092026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.57ms)16102026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000016112026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.59ms)16122026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.57ms)16132026-10-01 07:36:38.716 UTC [849] ERROR: relation "goose_db_version" does not exist at character 3616142026-10-01 07:36:38.716 UTC [849] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16152026/10/01 07:36:38 OK 3_commit_push.sql (2.49ms)16162026/10/01 07:36:38 goose: up to current file version: 316172026/10/01 07:36:38 OK 20241026095416_initial_model.sql (13.36ms)16182026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.62ms)16192026/10/01 07:36:38 OK 20241026095416_initial_model.sql (12.84ms)16202026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (2.07ms)16212026/10/01 07:36:38 OK 20251218171726_add_pins.sql (4.35ms)16222026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.62ms)16232026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)16242026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (3.48ms)16252026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4.9ms)16262026/10/01 07:36:38 INFO Received push request method=POST path=/api/pushes16272026/10/01 07:36:38 OK 20260905000000_add_claims.sql (4.11ms)16282026/10/01 07:36:38 OK 20241026095416_initial_model.sql (12.44ms)16292026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (1.97ms)16302026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)16312026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (1.9ms)16322026-10-01 07:36:38.740 UTC [868] ERROR: relation "goose_db_version" does not exist at character 3616332026-10-01 07:36:38.740 UTC [868] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16342026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.02ms)16352026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000016362026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (1.79ms)16372026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000016382026/10/01 07:36:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16392026/10/01 07:36:38 INFO Uploading ag41xsx2vlyy0qhy1b55c4cz17m8x8gl-pinned-file.txt (128B)16402026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.87ms)16412026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.84ms)16422026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.87ms)16432026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.77ms)16442026/10/01 07:36:38 OK 2_object_stats_trigger.sql (2.06ms)16452026/10/01 07:36:38 OK 3_commit_push.sql (1.47ms)16462026/10/01 07:36:38 goose: up to current file version: 316472026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (4.61ms)16482026/10/01 07:36:38 OK 3_commit_push.sql (2.13ms)16492026/10/01 07:36:38 goose: up to current file version: 316502026/10/01 07:36:38 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16512026/10/01 07:36:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16522026/10/01 07:36:38 WARN Failed to register uploaded object key=ag41xsx2vlyy0qhy1b55c4cz17m8x8gl.ls error="server returned 404: 404 page not found\n"16532026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.83ms)16542026/10/01 07:36:38 INFO Signed narinfos id=1 count=116552026/10/01 07:36:38 INFO Uploading 1 narinfos16562026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (3.29ms)16572026/10/01 07:36:38 INFO Received complete push request method=POST path=/api/pushes/1/complete16582026/10/01 07:36:38 WARN Failed to register uploaded object key=ag41xsx2vlyy0qhy1b55c4cz17m8x8gl.narinfo error="server returned 404: 404 page not found\n"16592026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10.2ms)16602026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.6ms)16612026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000016622026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)16632026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.22ms)16642026/10/01 07:36:38 OK 2_object_stats_trigger.sql (1.21ms)16652026/10/01 07:36:38 OK 3_commit_push.sql (1.03ms)16662026/10/01 07:36:38 goose: up to current file version: 316672026/10/01 07:36:38 OK 20251218171726_add_pins.sql (3.39ms)16682026/10/01 07:36:38 INFO Upload complete. (62ms)1669=== NAME TestClientIntegration1670 client_integration_test.go:286: Created store path: /build/TestClientIntegration2312813769/002/store/cqh9w3rliba3lm6z9h96s9c0n9ga52cy-test-file.txt16712026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)16722026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.33ms)16732026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.02ms)16742026-10-01 07:36:38.773 UTC [888] ERROR: relation "goose_db_version" does not exist at character 3616752026-10-01 07:36:38.773 UTC [888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16762026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (2.16ms)16772026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000016782026/10/01 07:36:38 OK 1_commit_pending_closure.sql (2.15ms)16792026/10/01 07:36:38 OK 2_object_stats_trigger.sql (978.97µs)16802026/10/01 07:36:38 OK 3_commit_push.sql (973.09µs)16812026/10/01 07:36:38 goose: up to current file version: 316822026/10/01 07:36:38 OK 20241026095416_initial_model.sql (10.88ms)16832026/10/01 07:36:38 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)16842026/10/01 07:36:38 OK 20251218171726_add_pins.sql (4.14ms)16852026/10/01 07:36:38 OK 20260628120000_add_object_size_and_stats.sql (3.88ms)16862026/10/01 07:36:38 OK 20260905000000_add_claims.sql (3.79ms)16872026/10/01 07:36:38 OK 20260920000000_drop_claims.sql (2.56ms)16882026/10/01 07:36:38 OK 20260923120000_add_pushes.sql (1.71ms)16892026/10/01 07:36:38 goose: successfully migrated database to version: 2026092312000016902026/10/01 07:36:38 OK 1_commit_pending_closure.sql (1.89ms)16912026/10/01 07:36:38 OK 2_object_stats_trigger.sql (889.53µs)16922026/10/01 07:36:38 OK 3_commit_push.sql (656.27µs)16932026/10/01 07:36:38 goose: up to current file version: 31694--- PASS: TestReadProxyInvalidPath (0.63s)1695=== CONT TestPush_OverlappingRootsStoreOneRowPerKey16962026/10/01 07:36:38 INFO Received push request method=POST path=/api/pushes16972026/10/01 07:36:38 INFO Received push request method=POST path=/api/pushes16982026/10/01 07:36:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16992026/10/01 07:36:38 INFO Uploading 0112dcl54kf60w5mln914f44cd9i43xc-unpinned-file.txt (128B)17002026/10/01 07:36:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17012026/10/01 07:36:38 INFO Uploading cqh9w3rliba3lm6z9h96s9c0n9ga52cy-test-file.txt (152B)1702=== NAME TestClientMultipleUploads1703 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads781129379/001/store/9qnjfnk3pjs3q6hndd0xy9vf2hy4cqn8-test-file-0.txt1704=== NAME TestClientWithDependencies1705 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies729585700/001/store/mkwj5lkkfa2zl5fy27pgwql28hfsmdnw-test-script17062026/10/01 07:36:38 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17072026/10/01 07:36:38 WARN Failed to register uploaded object key=0112dcl54kf60w5mln914f44cd9i43xc.ls error="server returned 404: 404 page not found\n"17082026/10/01 07:36:38 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17092026/10/01 07:36:38 WARN Failed to register uploaded object key=cqh9w3rliba3lm6z9h96s9c0n9ga52cy.ls error="server returned 404: 404 page not found\n"17102026/10/01 07:36:38 INFO Signed narinfos id=2 count=117112026/10/01 07:36:38 INFO Uploading 1 narinfos17122026/10/01 07:36:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17132026/10/01 07:36:38 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17142026/10/01 07:36:38 INFO Signed narinfos id=1 count=117152026/10/01 07:36:38 INFO Uploading 1 narinfos17162026/10/01 07:36:38 INFO Received complete push request method=POST path=/api/pushes/2/complete17172026/10/01 07:36:38 WARN Failed to register uploaded object key=0112dcl54kf60w5mln914f44cd9i43xc.narinfo error="server returned 404: 404 page not found\n"17182026/10/01 07:36:38 INFO Received complete push request method=POST path=/api/pushes/1/complete17192026/10/01 07:36:38 WARN Failed to register uploaded object key=cqh9w3rliba3lm6z9h96s9c0n9ga52cy.narinfo error="server returned 404: 404 page not found\n"17202026/10/01 07:36:38 INFO Upload complete. (52ms)17212026/10/01 07:36:38 INFO Upload complete. (55ms)1722 client_integration_test.go:615: Found 1 dependencies (including self)1723=== NAME TestClientCADerivations1724 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2415656032/001/store/kdh36qms307314wrsxyaw27jq2fckjv4-ca-test1725=== NAME TestClientMultipleUploads1726 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads781129379/001/store/dgvw6j4flpc9axlsalzkdbp933sr0340-test-file-1.txt17272026/10/01 07:36:38 INFO Received cleanup request method=DELETE path=/api/pending_closures17282026/10/01 07:36:38 INFO Aborted multipart uploads count=017292026/10/01 07:36:38 INFO Received uploads request method=POST path=/api/pending_closures1730--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.13s)1731=== CONT TestParseSingleRange1732=== RUN TestParseSingleRange/none1733=== PAUSE TestParseSingleRange/none1734=== RUN TestParseSingleRange/unknown_unit1735=== PAUSE TestParseSingleRange/unknown_unit1736=== RUN TestParseSingleRange/multi-range_ignored1737=== PAUSE TestParseSingleRange/multi-range_ignored1738=== RUN TestParseSingleRange/malformed_no_dash1739=== PAUSE TestParseSingleRange/malformed_no_dash1740=== RUN TestParseSingleRange/malformed_both_empty1741=== PAUSE TestParseSingleRange/malformed_both_empty1742=== RUN TestParseSingleRange/malformed_end_before_start1743=== PAUSE TestParseSingleRange/malformed_end_before_start1744=== RUN TestParseSingleRange/closed1745=== PAUSE TestParseSingleRange/closed1746=== RUN TestParseSingleRange/open-ended1747=== PAUSE TestParseSingleRange/open-ended1748=== RUN TestParseSingleRange/end_clamped_to_size1749=== PAUSE TestParseSingleRange/end_clamped_to_size1750=== RUN TestParseSingleRange/suffix1751=== PAUSE TestParseSingleRange/suffix1752=== RUN TestParseSingleRange/suffix_exceeds_size1753=== PAUSE TestParseSingleRange/suffix_exceeds_size1754=== RUN TestParseSingleRange/single_byte1755=== PAUSE TestParseSingleRange/single_byte1756=== RUN TestParseSingleRange/start_past_EOF1757=== PAUSE TestParseSingleRange/start_past_EOF1758=== RUN TestParseSingleRange/start_far_past_EOF1759=== PAUSE TestParseSingleRange/start_far_past_EOF1760=== CONT TestReadRedirectUsesPublicS3URL17612026/10/01 07:36:38 INFO Received create pin request method=POST path=/api/pins/myapp17622026-10-01 07:36:38.892 UTC [1122] ERROR: relation "goose_db_version" does not exist at character 3617632026-10-01 07:36:38.892 UTC [1122] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17642026/10/01 07:36:39 INFO All 1 paths already cached17652026/10/01 07:36:39 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3945341807/001/store/ag41xsx2vlyy0qhy1b55c4cz17m8x8gl-pinned-file.txt narinfo_key=ag41xsx2vlyy0qhy1b55c4cz17m8x8gl.narinfo17662026/10/01 07:36:39 INFO Received cleanup request method=DELETE path=/api/pending_closures1767=== NAME TestClientIntegration1768 client_integration_test.go:312: Retrieved narinfo from S3:1769 StorePath: /build/TestClientIntegration2312813769/002/store/cqh9w3rliba3lm6z9h96s9c0n9ga52cy-test-file.txt1770 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1771 Compression: zstd1772 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117732026/10/01 07:36:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures1774 NarSize: 1521775 References: 1776 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117772026/10/01 07:36:39 INFO Garbage collection started17782026/10/01 07:36:39 INFO Aborted multipart uploads count=11779 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1780 client_integration_test.go:313: Decompressed .ls content (64 bytes):1781 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1782 client_integration_test.go:316: Testing garbage collection...17832026/10/01 07:36:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17842026-10-01 07:36:39.167 UTC [519] ERROR: Closure does not exist: id=117852026-10-01 07:36:39.167 UTC [519] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE17862026-10-01 07:36:39.167 UTC [519] STATEMENT: -- name: CommitPendingClosure :exec1787 SELECT commit_pending_closure($1::bigint)1788 1789=== NAME TestClientCADerivations1790 client_ca_test.go:139: Found 1 dependencies (including self)1791--- PASS: TestService_cleanupPendingClosuresHandler (0.90s)1792=== CONT TestCompleteMultipartUnregistered1793=== NAME TestClientMultipleUploads1794 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads781129379/001/store/hiqkv9ddr9g0hjcizw4cjkv11ali3i9q-test-file-2.txt1795--- PASS: TestService_Rustfstest (0.82s)1796=== CONT TestReadProxyRangeRequest17972026/10/01 07:36:39 INFO Aborted multipart uploads count=017982026/10/01 07:36:39 WARN Force mode enabled - objects will be deleted immediately without grace period17992026/10/01 07:36:39 OK 20241026095416_initial_model.sql (70.2ms)18002026/10/01 07:36:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures18012026/10/01 07:36:39 INFO Received push request method=POST path=/api/pushes18022026/10/01 07:36:39 INFO Garbage collection started18032026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.82ms)18042026/10/01 07:36:39 OK 20251218171726_add_pins.sql (4.03ms)18052026/10/01 07:36:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18062026/10/01 07:36:39 INFO Uploading mkwj5lkkfa2zl5fy27pgwql28hfsmdnw-test-script (136B)18072026-10-01 07:36:39.241 UTC [1249] ERROR: relation "goose_db_version" does not exist at character 3618082026-10-01 07:36:39.241 UTC [1249] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18092026/10/01 07:36:39 INFO Aborted multipart uploads count=018102026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)18112026/10/01 07:36:39 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18122026/10/01 07:36:39 WARN Failed to register uploaded object key=mkwj5lkkfa2zl5fy27pgwql28hfsmdnw.ls error="server returned 404: 404 page not found\n"18132026/10/01 07:36:39 WARN Force mode enabled - objects will be deleted immediately without grace period18142026/10/01 07:36:39 WARN Failed to register uploaded object key=log/skkaj38l4x8zm6blnw6spb0a2v5v9wy7-test-script.drv error="server returned 404: 404 page not found\n"18152026/10/01 07:36:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18162026/10/01 07:36:39 INFO Signed narinfos id=1 count=118172026/10/01 07:36:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=018182026/10/01 07:36:39 INFO Uploading 1 narinfos18192026/10/01 07:36:39 OK 20260905000000_add_claims.sql (5.17ms)1820--- PASS: TestReadProxy404 (0.80s)1821=== CONT TestService_verifyS3Integrity18222026/10/01 07:36:39 INFO Vacuumed table table=pending_closures18232026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.65ms)18242026/10/01 07:36:39 INFO Vacuumed table table=pending_objects18252026/10/01 07:36:39 INFO Vacuumed table table=multipart_uploads18262026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (3.79ms)18272026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000018282026/10/01 07:36:39 INFO Received complete push request method=POST path=/api/pushes/1/complete18292026/10/01 07:36:39 WARN Failed to register uploaded object key=mkwj5lkkfa2zl5fy27pgwql28hfsmdnw.narinfo error="server returned 404: 404 page not found\n"18302026/10/01 07:36:39 OK 20241026095416_initial_model.sql (12.22ms)18312026/10/01 07:36:39 INFO Vacuumed table table=closures18322026/10/01 07:36:39 OK 1_commit_pending_closure.sql (3.35ms)18332026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)18342026/10/01 07:36:39 INFO Vacuumed table table=objects18352026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.76ms)18362026/10/01 07:36:39 OK 3_commit_push.sql (1.84ms)18372026/10/01 07:36:39 goose: up to current file version: 318382026/10/01 07:36:39 INFO Upload complete. (99ms)18392026/10/01 07:36:39 OK 20251218171726_add_pins.sql (3.43ms)18402026/10/01 07:36:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=01841=== NAME TestClientWithDependencies1842 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies729585700/001/store) requires matching store prefix18432026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.48ms)18442026/10/01 07:36:39 INFO Vacuumed table table=pending_closures18452026/10/01 07:36:39 INFO Received push request method=POST path=/api/pushes1846--- PASS: TestClientWithDependencies (1.15s)1847=== CONT TestIsValidUploadKey1848=== RUN TestIsValidUploadKey/narinfo1849=== PAUSE TestIsValidUploadKey/narinfo1850=== RUN TestIsValidUploadKey/nar_zst1851=== PAUSE TestIsValidUploadKey/nar_zst1852=== RUN TestIsValidUploadKey/nar_xz1853=== PAUSE TestIsValidUploadKey/nar_xz1854=== RUN TestIsValidUploadKey/nar_plain1855=== PAUSE TestIsValidUploadKey/nar_plain1856=== RUN TestIsValidUploadKey/listing1857=== PAUSE TestIsValidUploadKey/listing1858=== RUN TestIsValidUploadKey/build_log1859=== PAUSE TestIsValidUploadKey/build_log1860=== RUN TestIsValidUploadKey/build_log_home-manager_file1861=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1862=== RUN TestIsValidUploadKey/build_log_plus_in_name1863=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1864=== RUN TestIsValidUploadKey/build_log_question_mark1865=== PAUSE TestIsValidUploadKey/build_log_question_mark1866=== RUN TestIsValidUploadKey/build_log_equals1867=== PAUSE TestIsValidUploadKey/build_log_equals1868=== RUN TestIsValidUploadKey/realisation1869=== PAUSE TestIsValidUploadKey/realisation1870=== RUN TestIsValidUploadKey/realisation_plus_in_output1871=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1872=== RUN TestIsValidUploadKey/nix-cache-info1873=== PAUSE TestIsValidUploadKey/nix-cache-info1874=== RUN TestIsValidUploadKey/index.html1875=== PAUSE TestIsValidUploadKey/index.html1876=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1877=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1878=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1879=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1880=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1881=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1882=== RUN TestIsValidUploadKey/traversal1883=== PAUSE TestIsValidUploadKey/traversal1884=== RUN TestIsValidUploadKey/traversal_nar1885=== PAUSE TestIsValidUploadKey/traversal_nar1886=== RUN TestIsValidUploadKey/absolute1887=== PAUSE TestIsValidUploadKey/absolute1888=== RUN TestIsValidUploadKey/empty_key1889=== PAUSE TestIsValidUploadKey/empty_key1890=== RUN TestIsValidUploadKey/unknown_type1891=== PAUSE TestIsValidUploadKey/unknown_type1892=== CONT TestService_createPendingClosureHandler18932026/10/01 07:36:39 INFO Vacuumed table table=pending_objects18942026/10/01 07:36:39 INFO Vacuumed table table=multipart_uploads18952026/10/01 07:36:39 OK 20260905000000_add_claims.sql (4.82ms)18962026/10/01 07:36:39 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18972026/10/01 07:36:39 INFO Uploading hiqkv9ddr9g0hjcizw4cjkv11ali3i9q-test-file-2.txt (160B)18982026/10/01 07:36:39 INFO Uploading dgvw6j4flpc9axlsalzkdbp933sr0340-test-file-1.txt (160B)18992026/10/01 07:36:39 INFO Uploading 9qnjfnk3pjs3q6hndd0xy9vf2hy4cqn8-test-file-0.txt (160B)19002026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.87ms)19012026/10/01 07:36:39 INFO Vacuumed table table=closures19022026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures19032026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (3.25ms)19042026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000019052026/10/01 07:36:39 INFO Vacuumed table table=objects19062026/10/01 07:36:39 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19072026/10/01 07:36:39 WARN Failed to register uploaded object key=dgvw6j4flpc9axlsalzkdbp933sr0340.ls error="server returned 404: 404 page not found\n"19082026/10/01 07:36:39 WARN Failed to register uploaded object key=hiqkv9ddr9g0hjcizw4cjkv11ali3i9q.ls error="server returned 404: 404 page not found\n"19092026/10/01 07:36:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19102026/10/01 07:36:39 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19112026/10/01 07:36:39 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19122026/10/01 07:36:39 WARN Failed to register uploaded object key=9qnjfnk3pjs3q6hndd0xy9vf2hy4cqn8.ls error="server returned 404: 404 page not found\n"19132026/10/01 07:36:39 INFO Signed narinfos id=1 count=319142026/10/01 07:36:39 INFO Uploading 3 narinfos19152026/10/01 07:36:39 WARN Failed to register uploaded object key=dgvw6j4flpc9axlsalzkdbp933sr0340.narinfo error="server returned 404: 404 page not found\n"19162026/10/01 07:36:39 WARN Failed to register uploaded object key=9qnjfnk3pjs3q6hndd0xy9vf2hy4cqn8.narinfo error="server returned 404: 404 page not found\n"19172026/10/01 07:36:39 INFO Received complete push request method=POST path=/api/pushes/1/complete19182026/10/01 07:36:39 WARN Failed to register uploaded object key=hiqkv9ddr9g0hjcizw4cjkv11ali3i9q.narinfo error="server returned 404: 404 page not found\n"19192026/10/01 07:36:39 OK 1_commit_pending_closure.sql (11.87ms)19202026/10/01 07:36:39 OK 2_object_stats_trigger.sql (2.9ms)19212026/10/01 07:36:39 INFO Upload complete. (66ms)1922=== NAME TestClientMultipleUploads1923 client_integration_test.go:369: Uploaded 3 paths in 130.755926ms19242026/10/01 07:36:39 OK 3_commit_push.sql (1.62ms)19252026/10/01 07:36:39 goose: up to current file version: 31926--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.85s)1927=== CONT TestUploadHandlersRejectOversizedBody19282026-10-01 07:36:39.374 UTC [1295] ERROR: relation "goose_db_version" does not exist at character 3619292026-10-01 07:36:39.374 UTC [1295] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19302026-10-01 07:36:39.374 UTC [1312] ERROR: relation "goose_db_version" does not exist at character 3619312026-10-01 07:36:39.374 UTC [1312] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19322026/10/01 07:36:39 INFO Received push request method=POST path=/api/pushes19332026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures1934--- PASS: TestClientMultipleUploads (1.21s)1935=== CONT TestUploadHandlersRejectInvalidKeys1936=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1937=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1938=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1939=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1940=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1941=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19422026-10-01 07:36:39.381 UTC [1314] ERROR: relation "goose_db_version" does not exist at character 3619432026-10-01 07:36:39.381 UTC [1314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1944=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19452026-10-01 07:36:39.381 UTC [1313] ERROR: relation "goose_db_version" does not exist at character 3619462026-10-01 07:36:39.381 UTC [1313] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1947=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1948=== CONT TestProxyWriteTimeout1949=== RUN TestProxyWriteTimeout/narinfo1950=== PAUSE TestProxyWriteTimeout/narinfo1951=== RUN TestProxyWriteTimeout/1_GiB_nar1952=== PAUSE TestProxyWriteTimeout/1_GiB_nar1953=== RUN TestProxyWriteTimeout/10_GiB_nar1954=== PAUSE TestProxyWriteTimeout/10_GiB_nar1955=== RUN TestProxyWriteTimeout/unknown_size1956=== PAUSE TestProxyWriteTimeout/unknown_size1957=== CONT TestReadProxyRootRedirectsToIndexHTML19582026/10/01 07:36:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19592026/10/01 07:36:39 INFO Uploading kdh36qms307314wrsxyaw27jq2fckjv4-ca-test (144B)19602026/10/01 07:36:39 WARN Failed to register uploaded object key=kdh36qms307314wrsxyaw27jq2fckjv4.ls error="server returned 404: 404 page not found\n"19612026/10/01 07:36:39 WARN Failed to register uploaded object key=log/zrq4zk9ikbcxcybq3dclk4wqx1rfv3qs-ca-test.drv error="server returned 404: 404 page not found\n"19622026/10/01 07:36:39 OK 20241026095416_initial_model.sql (14.28ms)19632026/10/01 07:36:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19642026/10/01 07:36:39 OK 20241026095416_initial_model.sql (66.42ms)1965=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1966=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1967=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1968=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1969=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1970=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1971=== CONT TestReadRedirectNar19722026/10/01 07:36:39 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19732026/10/01 07:36:39 INFO Signed narinfos id=1 count=119742026/10/01 07:36:39 INFO Uploading 1 narinfos19752026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)19762026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.65ms)19772026/10/01 07:36:39 INFO Received complete push request method=POST path=/api/pushes/1/complete19782026/10/01 07:36:39 WARN Failed to register uploaded object key=kdh36qms307314wrsxyaw27jq2fckjv4.narinfo error="server returned 404: 404 page not found\n"19792026-10-01 07:36:39.465 UTC [1317] ERROR: relation "goose_db_version" does not exist at character 3619802026-10-01 07:36:39.465 UTC [1317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19812026/10/01 07:36:39 OK 20251218171726_add_pins.sql (4.11ms)1982--- PASS: TestReadProxyNarStreaming (0.93s)1983=== CONT TestReadProxyDisabled19842026/10/01 07:36:39 OK 20251218171726_add_pins.sql (4.91ms)19852026/10/01 07:36:39 OK 20241026095416_initial_model.sql (11.17ms)19862026/10/01 07:36:39 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst19872026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures19882026/10/01 07:36:39 INFO Upload complete. (237ms)19892026/10/01 07:36:39 OK 20241026095416_initial_model.sql (11.72ms)19902026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)1991--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.97s)1992=== CONT TestResurrectedObjectNotDeleted19932026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)19942026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (3.47ms)19952026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (3.15ms)1996=== NAME TestClientCADerivations1997 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2415656032/001/store/kdh36qms307314wrsxyaw27jq2fckjv4-ca-test1998 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1999 Compression: zstd2000 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2001 NarSize: 1442002 References: 2003 Deriver: /build/TestClientCADerivations2415656032/001/store/zrq4zk9ikbcxcybq3dclk4wqx1rfv3qs-ca-test.drv2004 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2005 client_ca_test.go:185: Checking for realisation files in S3...2006 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2007 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20082026/10/01 07:36:39 OK 20260905000000_add_claims.sql (7.48ms)20092026/10/01 07:36:39 OK 20260905000000_add_claims.sql (6.03ms)20102026/10/01 07:36:39 OK 20251218171726_add_pins.sql (5.74ms)20112026/10/01 07:36:39 OK 20251218171726_add_pins.sql (4.65ms)20122026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.25ms)20132026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.62ms)20142026/10/01 07:36:39 OK 20241026095416_initial_model.sql (12.87ms)20152026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)20162026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.89ms)20172026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000020182026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (5.66ms)20192026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (3.46ms)20202026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000020212026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)20222026/10/01 07:36:39 OK 1_commit_pending_closure.sql (2.89ms)20232026/10/01 07:36:39 OK 20260905000000_add_claims.sql (4.39ms)20242026/10/01 07:36:39 OK 2_object_stats_trigger.sql (2.21ms)20252026/10/01 07:36:39 OK 1_commit_pending_closure.sql (3.42ms)20262026/10/01 07:36:39 OK 20260905000000_add_claims.sql (5.07ms)20272026/10/01 07:36:39 OK 3_commit_push.sql (1.46ms)20282026/10/01 07:36:39 goose: up to current file version: 320292026/10/01 07:36:39 OK 20251218171726_add_pins.sql (4.53ms)20302026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.26ms)20312026/10/01 07:36:39 OK 2_object_stats_trigger.sql (2.11ms)20322026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (2.79ms)2033--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.96s)2034=== CONT TestCreatePin_ReservedPins20352026/10/01 07:36:39 OK 3_commit_push.sql (1.82ms)20362026/10/01 07:36:39 goose: up to current file version: 320372026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (8.95ms)20382026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000020392026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (11.22ms)20402026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (9.08ms)20412026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000020422026/10/01 07:36:39 OK 1_commit_pending_closure.sql (3.27ms)20432026/10/01 07:36:39 OK 1_commit_pending_closure.sql (2.5ms)20442026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.82ms)20452026/10/01 07:36:39 OK 20260905000000_add_claims.sql (4.54ms)20462026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.96ms)20472026/10/01 07:36:39 OK 3_commit_push.sql (1.56ms)20482026/10/01 07:36:39 goose: up to current file version: 320492026/10/01 07:36:39 OK 3_commit_push.sql (1.37ms)20502026/10/01 07:36:39 goose: up to current file version: 320512026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures20522026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.1ms)20532026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.39ms)20542026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000020552026/10/01 07:36:39 OK 1_commit_pending_closure.sql (4.04ms)20562026/10/01 07:36:39 OK 2_object_stats_trigger.sql (2.39ms)20572026/10/01 07:36:39 OK 3_commit_push.sql (1.26ms)20582026/10/01 07:36:39 goose: up to current file version: 320592026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures20602026-10-01 07:36:39.535 UTC [1343] ERROR: relation "goose_db_version" does not exist at character 3620612026-10-01 07:36:39.535 UTC [1343] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20622026-10-01 07:36:39.552 UTC [1361] ERROR: relation "goose_db_version" does not exist at character 3620632026-10-01 07:36:39.552 UTC [1361] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20642026-10-01 07:36:39.554 UTC [1404] ERROR: relation "goose_db_version" does not exist at character 3620652026-10-01 07:36:39.554 UTC [1404] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20662026/10/01 07:36:39 OK 20241026095416_initial_model.sql (10.83ms)20672026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.29ms)20682026/10/01 07:36:39 OK 20251218171726_add_pins.sql (7.02ms)2069=== NAME TestClientCADerivations2070 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2071 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2072 error: binary cache 's3://bucket29?endpoint=http://localhost:41257&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2415656032/001/store'2073 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12074--- PASS: TestClientCADerivations (1.45s)2075=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2076--- PASS: TestReadProxyNarinfo (1.02s)2077=== CONT TestService_NativeMTLS20782026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (15.36ms)20792026/10/01 07:36:39 OK 20241026095416_initial_model.sql (20.47ms)20802026/10/01 07:36:39 OK 20241026095416_initial_model.sql (14.87ms)20812026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)20822026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)20832026/10/01 07:36:39 OK 20260905000000_add_claims.sql (3.72ms)20842026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.34ms)20852026/10/01 07:36:39 OK 20251218171726_add_pins.sql (3.75ms)20862026/10/01 07:36:39 OK 20251218171726_add_pins.sql (4.11ms)20872026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.48ms)20882026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000020892026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.31ms)20902026/10/01 07:36:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20912026/10/01 07:36:39 OK 1_commit_pending_closure.sql (2.51ms)20922026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (5.14ms)20932026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.27ms)20942026/10/01 07:36:39 OK 3_commit_push.sql (2.26ms)20952026/10/01 07:36:39 goose: up to current file version: 320962026/10/01 07:36:39 OK 20260905000000_add_claims.sql (4.17ms)20972026/10/01 07:36:39 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGQ1ZjZmNWItYzIzZi00NTkzLThkMjMtZDhiM2ViNjI3YTdhLmI0MDczOTJlLTk5OTItNDFlMy04ZjJkLTYwMDczYWNkNzFlM3gxNzkwODQwMTk5NTQ0NzYwMzM520982026/10/01 07:36:39 OK 20260905000000_add_claims.sql (4.49ms)20992026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (2.97ms)21002026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (2.86ms)21012026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.82ms)21022026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000021032026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures21042026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.99ms)21052026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000021062026/10/01 07:36:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGQ1ZjZmNWItYzIzZi00NTkzLThkMjMtZDhiM2ViNjI3YTdhLmI0MDczOTJlLTk5OTItNDFlMy04ZjJkLTYwMDczYWNkNzFlM3gxNzkwODQwMTk5NTQ0NzYwMzM5 parts=12107--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.05s)2108=== CONT TestObjectStatsTrigger21092026/10/01 07:36:39 OK 1_commit_pending_closure.sql (3.23ms)21102026/10/01 07:36:39 OK 1_commit_pending_closure.sql (2.85ms)21112026/10/01 07:36:39 OK 2_object_stats_trigger.sql (2.23ms)21122026/10/01 07:36:39 OK 2_object_stats_trigger.sql (2.65ms)21132026/10/01 07:36:39 OK 3_commit_push.sql (1.51ms)21142026/10/01 07:36:39 goose: up to current file version: 321152026/10/01 07:36:39 OK 3_commit_push.sql (2.37ms)21162026/10/01 07:36:39 goose: up to current file version: 321172026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures2118=== RUN TestPush_RejectsBadRequests/bad_root2119=== PAUSE TestPush_RejectsBadRequests/bad_root2120=== RUN TestPush_RejectsBadRequests/root_not_in_objects2121=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2122=== RUN TestPush_RejectsBadRequests/no_roots2123=== PAUSE TestPush_RejectsBadRequests/no_roots2124=== RUN TestPush_RejectsBadRequests/no_objects2125=== PAUSE TestPush_RejectsBadRequests/no_objects2126=== CONT TestNARDeduplicationMetadataUploadBug21272026-10-01 07:36:39.645 UTC [1451] ERROR: relation "goose_db_version" does not exist at character 3621282026-10-01 07:36:39.645 UTC [1451] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21292026/10/01 07:36:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45661/oidc21302026-10-01 07:36:39.649 UTC [1452] ERROR: relation "goose_db_version" does not exist at character 3621312026-10-01 07:36:39.649 UTC [1452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21322026/10/01 07:36:39 INFO Received push request method=POST path=/api/pushes21332026/10/01 07:36:39 OK 20241026095416_initial_model.sql (10.66ms)21342026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)21352026/10/01 07:36:39 OK 20241026095416_initial_model.sql (11.75ms)21362026/10/01 07:36:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21372026/10/01 07:36:39 INFO Signed narinfos id=1 count=121382026/10/01 07:36:39 OK 20251218171726_add_pins.sql (3.21ms)2139--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.06s)2140=== CONT TestOrphanedObjectsGC21412026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)21422026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)21432026/10/01 07:36:39 OK 20251218171726_add_pins.sql (4.55ms)21442026/10/01 07:36:39 OK 20260905000000_add_claims.sql (3.31ms)21452026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)21462026/10/01 07:36:39 INFO Received push request method=POST path=/api/pushes21472026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.38ms)21482026/10/01 07:36:39 OK 20260905000000_add_claims.sql (3.96ms)21492026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (3.09ms)21502026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000021512026-10-01 07:36:39.684 UTC [1457] ERROR: relation "goose_db_version" does not exist at character 3621522026-10-01 07:36:39.684 UTC [1457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21532026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (2.56ms)21542026/10/01 07:36:39 OK 1_commit_pending_closure.sql (3.06ms)21552026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.64ms)21562026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000021572026/10/01 07:36:39 OK 2_object_stats_trigger.sql (2.01ms)21582026/10/01 07:36:39 OK 3_commit_push.sql (672.53µs)21592026/10/01 07:36:39 goose: up to current file version: 321602026/10/01 07:36:39 OK 1_commit_pending_closure.sql (1.79ms)21612026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.6ms)21622026/10/01 07:36:39 OK 3_commit_push.sql (1.13ms)21632026/10/01 07:36:39 goose: up to current file version: 321642026-10-01 07:36:39.699 UTC [1459] ERROR: relation "goose_db_version" does not exist at character 3621652026-10-01 07:36:39.699 UTC [1459] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21662026/10/01 07:36:39 INFO Received push request method=POST path=/api/pushes21672026/10/01 07:36:39 INFO Received complete push request method=POST path=/api/pushes/1/complete21682026/10/01 07:36:39 OK 20241026095416_initial_model.sql (13.91ms)21692026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)21702026/10/01 07:36:39 OK 20251218171726_add_pins.sql (4.03ms)21712026/10/01 07:36:39 INFO Received push request method=POST path=/api/pushes21722026/10/01 07:36:39 OK 20241026095416_initial_model.sql (11.64ms)21732026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (6.75ms)21742026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)21752026/10/01 07:36:39 OK 20260905000000_add_claims.sql (3.55ms)21762026/10/01 07:36:39 INFO Received complete push request method=POST path=/api/pushes/1/complete21772026/10/01 07:36:39 OK 20251218171726_add_pins.sql (3.44ms)21782026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.16ms)21792026-10-01 07:36:39.725 UTC [1464] ERROR: relation "goose_db_version" does not exist at character 3621802026-10-01 07:36:39.725 UTC [1464] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21812026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.45ms)21822026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000021832026/10/01 07:36:39 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket4219814740/001/proxy.sock21842026/10/01 07:36:39 INFO Starting HTTP server address=127.0.0.1:4411721852026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.81ms)21862026/10/01 07:36:39 WARN mTLS auth: subject not in bound subjects subject="CN=someone"21872026/10/01 07:36:39 INFO Shutdown signal received, draining in-flight requests timeout=10s21882026/10/01 07:36:39 OK 1_commit_pending_closure.sql (2.24ms)2189--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.03s)2190=== CONT TestMetricsInventory21912026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.53ms)21922026/10/01 07:36:39 OK 20260905000000_add_claims.sql (3.3ms)21932026/10/01 07:36:39 OK 3_commit_push.sql (667.43µs)21942026/10/01 07:36:39 goose: up to current file version: 32195--- PASS: TestPush_CompleteCommitsEveryRoot (1.07s)2196=== CONT TestMultipartCleanup21972026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (2.25ms)21982026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.21ms)21992026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000022002026/10/01 07:36:39 OK 1_commit_pending_closure.sql (1.91ms)22012026/10/01 07:36:39 OK 2_object_stats_trigger.sql (888.31µs)22022026/10/01 07:36:39 OK 3_commit_push.sql (552.33µs)22032026/10/01 07:36:39 goose: up to current file version: 322042026-10-01 07:36:39.741 UTC [1468] ERROR: relation "goose_db_version" does not exist at character 3622052026-10-01 07:36:39.741 UTC [1468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22062026/10/01 07:36:39 OK 20241026095416_initial_model.sql (10.51ms)22072026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)22082026/10/01 07:36:39 OK 20251218171726_add_pins.sql (3.4ms)22092026/10/01 07:36:39 INFO Received push request method=POST path=/api/pushes22102026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.37ms)22112026/10/01 07:36:39 OK 20260905000000_add_claims.sql (3.72ms)22122026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (2.91ms)22132026/10/01 07:36:39 OK 20241026095416_initial_model.sql (10.82ms)22142026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.45ms)22152026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (3.09ms)22162026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000022172026/10/01 07:36:39 OK 1_commit_pending_closure.sql (2.71ms)22182026/10/01 07:36:39 OK 20251218171726_add_pins.sql (4.01ms)22192026/10/01 07:36:39 OK 2_object_stats_trigger.sql (984.33µs)22202026/10/01 07:36:39 OK 3_commit_push.sql (1.2ms)22212026/10/01 07:36:39 goose: up to current file version: 32222--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.94s)2223=== CONT TestCreatePendingClosureRejectsOversizedNAR22242026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures2225--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)2226=== CONT TestServerTLSConfig2227=== RUN TestServerTLSConfig/no_client_CA2228=== PAUSE TestServerTLSConfig/no_client_CA2229=== RUN TestServerTLSConfig/missing_CA_file2230=== PAUSE TestServerTLSConfig/missing_CA_file2231=== RUN TestServerTLSConfig/not_a_PEM_file2232=== PAUSE TestServerTLSConfig/not_a_PEM_file2233=== CONT TestReadProxyConditionalGet22342026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (3.89ms)22352026/10/01 07:36:39 INFO Aborted multipart uploads count=022362026/10/01 07:36:39 OK 20260905000000_add_claims.sql (4.01ms)22372026/10/01 07:36:39 WARN Force mode enabled - objects will be deleted immediately without grace period22382026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (2.99ms)22392026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.75ms)22402026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000022412026/10/01 07:36:39 OK 1_commit_pending_closure.sql (4.02ms)22422026/10/01 07:36:39 OK 2_object_stats_trigger.sql (2.18ms)22432026/10/01 07:36:39 OK 3_commit_push.sql (1.86ms)22442026/10/01 07:36:39 goose: up to current file version: 322452026/10/01 07:36:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=02246--- PASS: TestReadRedirectUsesPublicS3URL (0.91s)2247=== CONT TestReadProxyHead22482026/10/01 07:36:39 INFO Vacuumed table table=pending_closures22492026/10/01 07:36:39 INFO Vacuumed table table=pending_objects22502026/10/01 07:36:39 INFO Vacuumed table table=multipart_uploads22512026/10/01 07:36:39 INFO Vacuumed table table=closures22522026/10/01 07:36:39 INFO Vacuumed table table=objects22532026/10/01 07:36:39 INFO Received complete push request method=POST path=/api/pushes/2/complete22542026-10-01 07:36:39.805 UTC [1476] ERROR: relation "goose_db_version" does not exist at character 3622552026-10-01 07:36:39.805 UTC [1476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2256--- PASS: TestReadProxyRangeRequest (0.64s)2257=== CONT TestCacheConfigHandlerMaxNarSize2258--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)2259=== CONT TestReadRedirectKeepsNarinfoProxied22602026-10-01 07:36:39.813 UTC [1477] ERROR: relation "goose_db_version" does not exist at character 3622612026-10-01 07:36:39.813 UTC [1477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2262--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.18s)2263=== CONT TestCacheConfigHandler/full_config,_no_issuer2264=== CONT TestCacheConfigHandler/no_signing_keys2265=== CONT TestCacheConfigHandler/no_cache_url_configured2266=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2267--- PASS: TestCacheConfigHandler (0.00s)2268 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2269 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2270 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2271 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2272=== CONT TestResolveDBConnectionString/flag_wins2273=== CONT TestResolveDBConnectionString/nothing_configured2274=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2275=== CONT TestResolveDBConnectionString/missing_file_is_an_error2276=== CONT TestResolveDBConnectionString/file_when_flag_empty2277=== CONT TestClientErrorHandling/InvalidStorePath2278--- PASS: TestResolveDBConnectionString (0.00s)2279 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2280 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2281 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2282 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2283 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)22842026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures22852026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures22862026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures22872026/10/01 07:36:39 OK 20241026095416_initial_model.sql (10.96ms)22882026/10/01 07:36:39 OK 20241026095416_initial_model.sql (9.93ms)22892026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)22902026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)22912026/10/01 07:36:39 OK 20251218171726_add_pins.sql (4.54ms)22922026/10/01 07:36:39 OK 20251218171726_add_pins.sql (3.87ms)22932026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.16ms)22942026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)22952026/10/01 07:36:39 OK 20260905000000_add_claims.sql (3.76ms)22962026/10/01 07:36:39 OK 20260905000000_add_claims.sql (4.56ms)22972026/10/01 07:36:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22982026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.82ms)22992026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.57ms)23002026/10/01 07:36:39 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst2301--- PASS: TestCompleteMultipartUnregistered (0.68s)2302=== CONT TestClientErrorHandling/InvalidAuthToken23032026-10-01 07:36:39.850 UTC [1482] ERROR: relation "goose_db_version" does not exist at character 3623042026-10-01 07:36:39.850 UTC [1482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23052026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.6ms)23062026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000023072026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (3.1ms)23082026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000023092026/10/01 07:36:39 OK 1_commit_pending_closure.sql (2.81ms)23102026/10/01 07:36:39 OK 1_commit_pending_closure.sql (2.44ms)23112026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.54ms)23122026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.58ms)23132026/10/01 07:36:39 OK 3_commit_push.sql (1.18ms)23142026/10/01 07:36:39 goose: up to current file version: 323152026/10/01 07:36:39 OK 3_commit_push.sql (1.91ms)23162026/10/01 07:36:39 goose: up to current file version: 323172026-10-01 07:36:39.865 UTC [1485] ERROR: relation "goose_db_version" does not exist at character 3623182026-10-01 07:36:39.865 UTC [1485] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23192026/10/01 07:36:39 OK 20241026095416_initial_model.sql (12.36ms)23202026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures23212026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)23222026/10/01 07:36:39 OK 20251218171726_add_pins.sql (10.59ms)23232026-10-01 07:36:39.885 UTC [1486] ERROR: relation "goose_db_version" does not exist at character 3623242026-10-01 07:36:39.885 UTC [1486] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23252026/10/01 07:36:39 OK 20241026095416_initial_model.sql (11.87ms)23262026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.55ms)23272026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.2ms)23282026/10/01 07:36:39 OK 20251218171726_add_pins.sql (3.86ms)23292026/10/01 07:36:39 OK 20260905000000_add_claims.sql (4.66ms)23302026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (2.69ms)23312026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (4.19ms)23322026-10-01 07:36:39.899 UTC [1487] ERROR: relation "goose_db_version" does not exist at character 3623332026-10-01 07:36:39.899 UTC [1487] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23342026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.88ms)23352026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000023362026/10/01 07:36:39 OK 20260905000000_add_claims.sql (3.59ms)23372026/10/01 07:36:39 OK 1_commit_pending_closure.sql (2.76ms)23382026/10/01 07:36:39 OK 20241026095416_initial_model.sql (10.72ms)23392026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (3.33ms)2340--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.52s)2341=== CONT TestClientErrorHandling/ServerNotAvailable23422026/10/01 07:36:39 OK 2_object_stats_trigger.sql (2.53ms)23432026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)23442026/10/01 07:36:39 OK 3_commit_push.sql (1.15ms)23452026/10/01 07:36:39 goose: up to current file version: 323462026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.33ms)23472026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000023482026/10/01 07:36:39 OK 1_commit_pending_closure.sql (2.26ms)23492026/10/01 07:36:39 OK 20251218171726_add_pins.sql (3.2ms)23502026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.17ms)23512026/10/01 07:36:39 OK 3_commit_push.sql (1.12ms)23522026/10/01 07:36:39 goose: up to current file version: 323532026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (3.63ms)23542026/10/01 07:36:39 OK 20241026095416_initial_model.sql (8.9ms)23552026/10/01 07:36:39 OK 20260905000000_add_claims.sql (2.8ms)23562026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (1.93ms)23572026/10/01 07:36:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23582026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (2.28ms)23592026-10-01 07:36:39.920 UTC [1489] ERROR: relation "goose_db_version" does not exist at character 3623602026-10-01 07:36:39.920 UTC [1489] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23612026/10/01 07:36:39 OK 20251218171726_add_pins.sql (3.36ms)23622026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.06ms)23632026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000023642026/10/01 07:36:39 OK 1_commit_pending_closure.sql (3.04ms)23652026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)23662026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.08ms)23672026/10/01 07:36:39 OK 3_commit_push.sql (733.51µs)23682026/10/01 07:36:39 goose: up to current file version: 323692026/10/01 07:36:39 OK 20260905000000_add_claims.sql (3.52ms)23702026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (2.45ms)23712026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (2.33ms)23722026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000023732026/10/01 07:36:39 OK 20241026095416_initial_model.sql (8.72ms)23742026/10/01 07:36:39 OK 1_commit_pending_closure.sql (1.82ms)23752026/10/01 07:36:39 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)23762026/10/01 07:36:39 OK 2_object_stats_trigger.sql (1.22ms)23772026/10/01 07:36:39 OK 3_commit_push.sql (804.35µs)23782026/10/01 07:36:39 goose: up to current file version: 323792026/10/01 07:36:39 OK 20251218171726_add_pins.sql (2.52ms)23802026/10/01 07:36:39 OK 20260628120000_add_object_size_and_stats.sql (3.07ms)23812026/10/01 07:36:39 OK 20260905000000_add_claims.sql (3.32ms)23822026/10/01 07:36:39 OK 20260920000000_drop_claims.sql (1.74ms)23832026/10/01 07:36:39 OK 20260923120000_add_pushes.sql (1.54ms)23842026/10/01 07:36:39 goose: successfully migrated database to version: 2026092312000023852026/10/01 07:36:39 OK 1_commit_pending_closure.sql (1.76ms)23862026/10/01 07:36:39 OK 2_object_stats_trigger.sql (773.99µs)23872026/10/01 07:36:39 OK 3_commit_push.sql (977.33µs)23882026/10/01 07:36:39 goose: up to current file version: 323892026/10/01 07:36:39 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MGQ1ZjZmNWItYzIzZi00NTkzLThkMjMtZDhiM2ViNjI3YTdhLjI2ZjUyNDUyLTcyOWUtNDdiNC1hMGVlLTJkYzg4Mjg0NDYzMHgxNzkwODQwMTk5NTE5MDYxOTk3 parts=122390--- PASS: TestReadRedirectNar (0.51s)2391=== CONT TestService_RequireScope_OIDC/builder_may_write23922026/10/01 07:36:39 INFO Received uploads request method=POST path=/api/pending_closures2393=== CONT TestService_RequireScope_OIDC/static_token_may_admin2394=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2395=== CONT TestService_RequireScope_OIDC/writer_implies_read2396=== CONT TestService_RequireScope_OIDC/reader_may_read2397=== CONT TestService_RequireScope_OIDC/static_token_may_write2398=== CONT TestService_RequireScope_OIDC/ops_may_not_write2399--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.43s)2400=== CONT TestService_RequireScope_OIDC/reader_may_not_write2401=== CONT TestService_RequireScope_OIDC/ops_may_admin2402=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2403=== CONT TestIsValidCachePath/narinfo2404=== CONT TestIsValidCachePath/short_hash2405=== CONT TestIsValidCachePath/leading_slash2406=== CONT TestIsValidCachePath/empty2407=== CONT TestIsValidCachePath/random_path2408=== CONT TestIsValidCachePath/wrong_extension2409=== CONT TestIsValidCachePath/invalid_char_e2410=== CONT TestIsValidCachePath/traversal_in_middle2411=== CONT TestIsValidCachePath/traversal_parent2412=== CONT TestIsValidCachePath/index.html2413=== CONT TestIsValidCachePath/invalid_char_u2414=== CONT TestIsValidCachePath/nix-cache-info2415=== CONT TestIsValidCachePath/log2416=== CONT TestIsValidCachePath/realisation2417=== CONT TestIsValidCachePath/nar_zst2418=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2419=== CONT TestIsValidCachePath/nar_xz2420=== CONT TestIsValidCachePath/ls2421=== CONT TestIsValidCachePath/nar_bz22422=== CONT TestIsValidCachePath/nar_uncompressed2423--- PASS: TestIsValidCachePath (0.00s)2424 --- PASS: TestIsValidCachePath/narinfo (0.00s)2425 --- PASS: TestIsValidCachePath/short_hash (0.00s)2426 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2427 --- PASS: TestIsValidCachePath/empty (0.00s)2428 --- PASS: TestIsValidCachePath/random_path (0.00s)2429 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2430 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2431 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2432 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2433 --- PASS: TestIsValidCachePath/index.html (0.00s)2434 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2435 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2436 --- PASS: TestIsValidCachePath/log (0.00s)2437 --- PASS: TestIsValidCachePath/realisation (0.00s)2438 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2439 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2440 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2441 --- PASS: TestIsValidCachePath/ls (0.00s)2442 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2443 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2444=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2445=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected24462026/10/01 07:36:39 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2447=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2448=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2449--- PASS: TestService_RequireScope_OIDC (0.84s)2450 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2451 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2452 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2453 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2454 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2455 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2456 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2457 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2458 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2459 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)24602026/10/01 07:36:39 WARN Authentication failed token_preview=eyJhbGciOi...NaIGSYZaEQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2461=== CONT TestParseSingleRange/none2462=== CONT TestParseSingleRange/open-ended2463=== CONT TestParseSingleRange/start_far_past_EOF2464=== CONT TestParseSingleRange/start_past_EOF2465=== CONT TestParseSingleRange/single_byte2466=== CONT TestParseSingleRange/suffix_exceeds_size2467=== CONT TestParseSingleRange/suffix2468=== CONT TestParseSingleRange/end_clamped_to_size2469=== CONT TestParseSingleRange/malformed_both_empty2470=== CONT TestParseSingleRange/closed2471=== CONT TestParseSingleRange/malformed_end_before_start2472=== CONT TestParseSingleRange/multi-range_ignored2473=== CONT TestParseSingleRange/malformed_no_dash2474=== CONT TestParseSingleRange/unknown_unit2475--- PASS: TestParseSingleRange (0.00s)2476 --- PASS: TestParseSingleRange/none (0.00s)2477 --- PASS: TestParseSingleRange/open-ended (0.00s)2478 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2479 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2480 --- PASS: TestParseSingleRange/single_byte (0.00s)2481 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2482 --- PASS: TestParseSingleRange/suffix (0.00s)2483 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2484 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2485 --- PASS: TestParseSingleRange/closed (0.00s)2486 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2487 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2488 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2489 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2490=== CONT TestIsValidUploadKey/narinfo2491=== CONT TestIsValidUploadKey/realisation_plus_in_output2492=== CONT TestIsValidUploadKey/unknown_type2493=== CONT TestIsValidUploadKey/absolute2494=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2495=== CONT TestIsValidUploadKey/index.html2496=== CONT TestIsValidUploadKey/nix-cache-info2497=== CONT TestIsValidUploadKey/traversal2498=== CONT TestIsValidUploadKey/traversal_nar2499=== CONT TestIsValidUploadKey/build_log_home-manager_file2500=== CONT TestIsValidUploadKey/empty_key2501=== CONT TestIsValidUploadKey/build_log_equals2502=== CONT TestIsValidUploadKey/build_log_question_mark2503=== CONT TestIsValidUploadKey/realisation2504=== CONT TestIsValidUploadKey/nar_plain2505=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2506=== CONT TestIsValidUploadKey/build_log_plus_in_name2507=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2508=== CONT TestIsValidUploadKey/listing2509=== CONT TestIsValidUploadKey/nar_xz2510=== CONT TestIsValidUploadKey/nar_zst2511=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2512=== CONT TestIsValidUploadKey/build_log2513--- PASS: TestIsValidUploadKey (0.00s)2514 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2515 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2516 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2517 --- PASS: TestIsValidUploadKey/absolute (0.00s)2518 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2519 --- PASS: TestIsValidUploadKey/index.html (0.00s)2520 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2521 --- PASS: TestIsValidUploadKey/traversal (0.00s)2522 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2523 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2524 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2525 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2526 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2527 --- PASS: TestIsValidUploadKey/realisation (0.00s)2528 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2529 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2530 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2531 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2532 --- PASS: TestIsValidUploadKey/listing (0.00s)2533 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2534 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2535 --- PASS: TestIsValidUploadKey/build_log (0.00s)2536=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2537--- PASS: TestService_AuthMiddleware_OIDC (0.95s)2538 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2539 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2540 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2541 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)25422026/10/01 07:36:39 INFO Received uploads request method=POST path=/2543=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal25442026/10/01 07:36:39 INFO Received complete multipart upload request method=POST path=/2545=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key25462026/10/01 07:36:39 INFO Received request for more parts method=POST path=/2547=== CONT TestProxyWriteTimeout/narinfo25482026/10/01 07:36:39 INFO Received uploads request method=POST path=/2549=== CONT TestProxyWriteTimeout/10_GiB_nar2550--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2551 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2552 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2553 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2554 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2555=== CONT TestProxyWriteTimeout/unknown_size2556=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure2557=== CONT TestProxyWriteTimeout/1_GiB_nar2558--- PASS: TestProxyWriteTimeout (0.00s)2559 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2560 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2561 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2562 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)25632026/10/01 07:36:39 INFO Received uploads request method=POST path=/2564=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts25652026/10/01 07:36:39 INFO Received request for more parts method=POST path=/2566--- PASS: TestReadProxyDisabled (0.51s)2567=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart25682026/10/01 07:36:39 INFO Received complete multipart upload request method=POST path=/25692026/10/01 07:36:39 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present25702026/10/01 07:36:40 INFO Received uploads request method=POST path=/api/pending_closures25712026/10/01 07:36:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2572=== CONT TestPush_RejectsBadRequests/bad_root25732026/10/01 07:36:40 INFO Received push request method=POST path=/api/pushes2574=== CONT TestPush_RejectsBadRequests/no_roots25752026/10/01 07:36:40 INFO Received push request method=POST path=/api/pushes2576=== CONT TestPush_RejectsBadRequests/no_objects25772026/10/01 07:36:40 INFO Received push request method=POST path=/api/pushes2578=== CONT TestPush_RejectsBadRequests/root_not_in_objects25792026/10/01 07:36:40 INFO Received push request method=POST path=/api/pushes2580=== CONT TestServerTLSConfig/no_client_CA2581=== CONT TestServerTLSConfig/missing_CA_file2582--- PASS: TestPush_RejectsBadRequests (1.01s)2583 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2584 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2585 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2586 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2587=== CONT TestServerTLSConfig/not_a_PEM_file2588--- PASS: TestServerTLSConfig (0.00s)2589 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2590 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2591 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2592--- PASS: TestResurrectedObjectNotDeleted (0.56s)25932026/10/01 07:36:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MGQ1ZjZmNWItYzIzZi00NTkzLThkMjMtZDhiM2ViNjI3YTdhLjhlYzFjNDUzLWE1ZTUtNDYzMi1hMmMzLWY4YWY0ODQ1N2NmNngxNzkwODQwMTk5NjExNzkzOTU2 parts=1225942026/10/01 07:36:40 WARN mTLS auth: subject not in bound subjects subject="CN=reader"25952026/10/01 07:36:40 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2596--- PASS: TestRedundantMultipartUpload (1.46s)2597--- PASS: TestService_NativeMTLS (0.46s)2598--- PASS: TestObjectStatsTrigger (0.47s)25992026/10/01 07:36:40 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.089641ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present26002026/10/01 07:36:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete26012026/10/01 07:36:40 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux26022026/10/01 07:36:40 WARN Refused reserved pin name=worker-x86_64-linux26032026/10/01 07:36:40 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux26042026/10/01 07:36:40 INFO Received create pin request method=POST path=/api/pins/my-app26052026/10/01 07:36:40 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2606--- PASS: TestCreatePin_ReservedPins (0.63s)2607=== NAME TestNARDeduplicationMetadataUploadBug2608 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2698931644/001/store/9p59y68kv708rsjxhpa9avpl8l7lhs4k-file1.txt26092026/10/01 07:36:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete26102026/10/01 07:36:40 INFO Received uploads request method=POST path=/api/pending_closures26112026/10/01 07:36:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MGQ1ZjZmNWItYzIzZi00NTkzLThkMjMtZDhiM2ViNjI3YTdhLmU4MzkwNzA1LTBkMGItNDY1ZC04NTc2LTZkNGI4YzczMTYxMngxNzkwODQwMTk5ODMwOTc5NjAz parts=1026122026/10/01 07:36:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete26132026/10/01 07:36:40 INFO Completed upload id=126142026/10/01 07:36:40 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000026152026/10/01 07:36:40 INFO Received uploads request method=POST path=/api/pending_closures26162026/10/01 07:36:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures26172026/10/01 07:36:40 INFO Aborted multipart uploads count=026182026/10/01 07:36:40 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=026192026/10/01 07:36:40 INFO Received push request method=POST path=/api/pushes26202026/10/01 07:36:40 INFO Vacuumed table table=pending_closures2621--- PASS: TestMetricsInventory (0.47s)26222026/10/01 07:36:40 INFO Vacuumed table table=pending_objects26232026/10/01 07:36:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)26242026/10/01 07:36:40 INFO Uploading 9p59y68kv708rsjxhpa9avpl8l7lhs4k-file1.txt (160B)26252026/10/01 07:36:40 INFO Vacuumed table table=multipart_uploads26262026/10/01 07:36:40 INFO Vacuumed table table=closures26272026/10/01 07:36:40 INFO Vacuumed table table=objects26282026/10/01 07:36:40 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"26292026/10/01 07:36:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign26302026/10/01 07:36:40 WARN Failed to register uploaded object key=9p59y68kv708rsjxhpa9avpl8l7lhs4k.ls error="server returned 404: 404 page not found\n"26312026/10/01 07:36:40 INFO Signed narinfos id=1 count=126322026/10/01 07:36:40 INFO Uploading 1 narinfos26332026/10/01 07:36:40 INFO Received complete push request method=POST path=/api/pushes/1/complete26342026/10/01 07:36:40 WARN Failed to register uploaded object key=9p59y68kv708rsjxhpa9avpl8l7lhs4k.narinfo error="server returned 404: 404 page not found\n"26352026/10/01 07:36:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete26362026/10/01 07:36:40 INFO Upload complete. (63ms)2637=== NAME TestNARDeduplicationMetadataUploadBug2638 metadata_upload_test.go:54: Retrieved narinfo from S3:2639 StorePath: /build/TestNARDeduplicationMetadataUploadBug2698931644/001/store/9p59y68kv708rsjxhpa9avpl8l7lhs4k-file1.txt2640 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2641 Compression: zstd2642 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2643 NarSize: 1602644 References: 2645 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2646 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2647 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2648 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}26492026/10/01 07:36:40 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002650--- PASS: TestService_createPendingClosureHandler (0.96s)2651--- PASS: TestReadProxyConditionalGet (0.47s)26522026/10/01 07:36:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MGQ1ZjZmNWItYzIzZi00NTkzLThkMjMtZDhiM2ViNjI3YTdhLjJmOGI5YTE4LWZlNzctNGM1Ni1iM2U5LTUyMjVhZjY1N2NhMHgxNzkwODQwMTk5ODg3MzM0MTg4 parts=1026532026/10/01 07:36:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete26542026/10/01 07:36:40 INFO Completed upload id=126552026/10/01 07:36:40 INFO Received uploads request method=POST path=/api/pending_closures26562026/10/01 07:36:40 INFO Received uploads request method=POST path=/api/pending_closures26572026/10/01 07:36:40 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo26582026/10/01 07:36:40 WARN Found objects in DB but missing from S3, will re-upload count=12659--- PASS: TestService_verifyS3Integrity (1.00s)26602026/10/01 07:36:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=426.139714ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2661=== NAME TestNARDeduplicationMetadataUploadBug2662 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2698931644/001/store/lhwpap009jr2304m8ch66symlbs6skqw-file2.txt2663--- PASS: TestReadProxyHead (0.48s)26642026/10/01 07:36:40 INFO Received cleanup request method=DELETE path=/api/pending_closures26652026/10/01 07:36:40 INFO Aborted multipart uploads count=12666--- PASS: TestMultipartCleanup (0.55s)2667--- PASS: TestReadRedirectKeepsNarinfoProxied (0.52s)26682026/10/01 07:36:40 INFO Received push request method=POST path=/api/pushes26692026/10/01 07:36:40 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)26702026/10/01 07:36:40 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign26712026/10/01 07:36:40 WARN Failed to register uploaded object key=lhwpap009jr2304m8ch66symlbs6skqw.ls error="server returned 404: 404 page not found\n"26722026/10/01 07:36:40 INFO Signed narinfos id=2 count=126732026/10/01 07:36:40 INFO Uploading 1 narinfos26742026/10/01 07:36:40 INFO Received complete push request method=POST path=/api/pushes/2/complete26752026/10/01 07:36:40 WARN Failed to register uploaded object key=lhwpap009jr2304m8ch66symlbs6skqw.narinfo error="server returned 404: 404 page not found\n"26762026/10/01 07:36:40 INFO Upload complete. (53ms)2677=== NAME TestNARDeduplicationMetadataUploadBug2678 metadata_upload_test.go:76: Retrieved narinfo from S3:2679 StorePath: /build/TestNARDeduplicationMetadataUploadBug2698931644/001/store/lhwpap009jr2304m8ch66symlbs6skqw-file2.txt2680 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2681 Compression: zstd2682 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2683 NarSize: 1602684 References: 2685 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2686 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2687 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2688 {"version":1,"root":{"type":"regular","size":44}}2689--- PASS: TestNARDeduplicationMetadataUploadBug (0.74s)26902026/10/01 07:36:40 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2691=== NAME TestOrphanedObjectsGC2692 orphaned_objects_gc_test.go:290: GC Test Summary:2693 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2694 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2695 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2696 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2697 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2698--- PASS: TestOrphanedObjectsGC (0.83s)26992026/10/01 07:36:40 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"27002026/10/01 07:36:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=783.662997ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2701--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2702 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2703 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2704 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.73s)2705=== NAME TestOrphanedObjectsGCStressTest2706 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2707 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion27082026/10/01 07:36:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02709=== NAME TestPinProtectsFromGC2710 client_integration_test.go:794: Pin successfully protected closure from garbage collection2711--- PASS: TestPinProtectsFromGC (3.42s)2712=== NAME TestOrphanedObjectsGCStressTest2713 orphaned_objects_gc_test.go:509: Stress test completed successfully:2714 orphaned_objects_gc_test.go:510: - Active objects preserved: 202715 orphaned_objects_gc_test.go:511: - Objects deleted: 2102716 orphaned_objects_gc_test.go:512: - Total GC'd: 2102717--- PASS: TestOrphanedObjectsGCStressTest (2.97s)27182026/10/01 07:36:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02719=== NAME TestClientIntegration2720 client_integration_test.go:323: Objects in database after GC:2721 client_integration_test.go:323: Successfully deleted all objects with GC --force2722--- PASS: TestClientIntegration (3.15s)27232026/10/01 07:36:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.697018989s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present27242026/10/01 07:36:42 WARN Rate limiter enabled after throttle name=s3-test rate=527252026/10/01 07:36:42 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2726=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2727 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102728 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002729--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (2.54s)27302026/10/01 07:36:43 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27312026/10/01 07:36:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.056788ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27322026/10/01 07:36:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=397.84582ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27332026/10/01 07:36:43 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=823.228088ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27342026/10/01 07:36:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.749169057s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27352026/10/01 07:36:46 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"27362026/10/01 07:36:46 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27372026/10/01 07:36:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.199617ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27382026/10/01 07:36:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.444913ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27392026/10/01 07:36:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=876.10341ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27402026/10/01 07:36:48 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.612892816s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config27412026/10/01 07:36:49 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27422026/10/01 07:36:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.517563ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27432026/10/01 07:36:50 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.688206ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27442026/10/01 07:36:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=830.132465ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures27452026/10/01 07:36:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.682175243s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2746--- PASS: TestClientErrorHandling (0.00s)2747 --- PASS: TestClientErrorHandling/InvalidStorePath (0.59s)2748 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.68s)2749 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.98s)2750PASS27512026-10-01 07:36:53.111 UTC [128] LOG: received smart shutdown request27522026-10-01 07:36:53.115 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 127532026-10-01 07:36:53.127 UTC [133] LOG: shutting down27542026-10-01 07:36:53.128 UTC [133] LOG: checkpoint starting: shutdown immediate27552026-10-01 07:36:53.991 UTC [133] LOG: checkpoint complete: wrote 10585 buffers (64.6%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 20 recycled; write=0.196 s, sync=0.645 s, total=0.864 s; sync files=23917, longest=0.088 s, average=0.001 s; distance=325406 kB, estimate=325406 kB; lsn=0/1552D5B0, redo lsn=0/1552D5B027562026-10-01 07:36:54.061 UTC [128] LOG: database system is shut down2757Running OIDC tests...2758=== RUN TestAudienceForIssuer2759=== PAUSE TestAudienceForIssuer2760=== RUN TestGlobMatch2761=== PAUSE TestGlobMatch2762=== RUN TestValidateToken_ValidToken2763=== PAUSE TestValidateToken_ValidToken2764=== RUN TestValidateToken_WrongAudience2765=== PAUSE TestValidateToken_WrongAudience2766=== RUN TestValidateToken_Expired2767=== PAUSE TestValidateToken_Expired2768=== RUN TestValidateToken_BoundClaimsMismatch2769=== PAUSE TestValidateToken_BoundClaimsMismatch2770=== RUN TestValidateToken_BoundSubjectMismatch2771=== PAUSE TestValidateToken_BoundSubjectMismatch2772=== RUN TestValidateToken_MultipleProviders2773=== PAUSE TestValidateToken_MultipleProviders2774=== RUN TestValidateToken_NoMatchingProvider2775=== PAUSE TestValidateToken_NoMatchingProvider2776=== RUN TestValidateToken_KubernetesServiceAccount2777=== PAUSE TestValidateToken_KubernetesServiceAccount2778=== RUN TestNewValidator_KubernetesRequiresCA2779=== PAUSE TestNewValidator_KubernetesRequiresCA2780=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2781=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2782=== RUN TestPins_ReservedForMatchingRule2783=== PAUSE TestPins_ReservedForMatchingRule2784=== RUN TestPins_TopLevelShorthand2785=== PAUSE TestPins_TopLevelShorthand2786=== RUN TestPins_ConfigValidation2787=== PAUSE TestPins_ConfigValidation2788=== RUN TestScopes_LegacyProviderDefaultsToWrite2789=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2790=== RUN TestScopes_Rules2791=== PAUSE TestScopes_Rules2792=== RUN TestScopes_ConfigValidation2793=== PAUSE TestScopes_ConfigValidation2794=== CONT TestAudienceForIssuer2795=== CONT TestPins_ReservedForMatchingRule2796--- PASS: TestAudienceForIssuer (0.00s)2797=== CONT TestValidateToken_BoundSubjectMismatch2798=== CONT TestValidateToken_BoundClaimsMismatch2799=== CONT TestValidateToken_ValidToken2800=== CONT TestScopes_ConfigValidation2801=== CONT TestScopes_Rules2802=== CONT TestScopes_LegacyProviderDefaultsToWrite2803=== CONT TestValidateToken_MultipleProviders2804=== CONT TestValidateToken_NoMatchingProvider2805=== CONT TestValidateToken_WrongAudience2806=== CONT TestValidateToken_Expired2807=== CONT TestGlobMatch2808--- PASS: TestScopes_ConfigValidation (0.00s)2809=== RUN TestGlobMatch/foo_foo2810=== PAUSE TestGlobMatch/foo_foo2811=== RUN TestGlobMatch/foo_bar2812=== PAUSE TestGlobMatch/foo_bar2813=== RUN TestGlobMatch/*_2814=== PAUSE TestGlobMatch/*_2815=== RUN TestGlobMatch/*_anything2816=== PAUSE TestGlobMatch/*_anything2817=== RUN TestGlobMatch/foo*_foo2818=== PAUSE TestGlobMatch/foo*_foo2819=== RUN TestGlobMatch/foo*_foobar2820=== PAUSE TestGlobMatch/foo*_foobar2821=== RUN TestGlobMatch/foo*_bar2822=== PAUSE TestGlobMatch/foo*_bar2823=== RUN TestGlobMatch/*bar_bar2824=== PAUSE TestGlobMatch/*bar_bar2825=== RUN TestGlobMatch/*bar_foobar2826=== PAUSE TestGlobMatch/*bar_foobar2827=== RUN TestGlobMatch/*bar_foo2828=== PAUSE TestGlobMatch/*bar_foo2829=== RUN TestGlobMatch/foo*bar_foobar2830=== PAUSE TestGlobMatch/foo*bar_foobar2831=== RUN TestGlobMatch/foo*bar_foo123bar2832=== PAUSE TestGlobMatch/foo*bar_foo123bar2833=== RUN TestGlobMatch/foo*bar_foobarbaz2834=== PAUSE TestGlobMatch/foo*bar_foobarbaz2835=== CONT TestPins_ConfigValidation2836=== CONT TestPins_TopLevelShorthand2837=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2838=== CONT TestNewValidator_KubernetesRequiresCA2839=== RUN TestGlobMatch/*/*_foo/bar2840=== PAUSE TestGlobMatch/*/*_foo/bar2841=== RUN TestGlobMatch/*/*_foo2842=== PAUSE TestGlobMatch/*/*_foo2843=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2844=== CONT TestValidateToken_KubernetesServiceAccount2845=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2846--- PASS: TestPins_ConfigValidation (0.00s)2847=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02848=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02849=== RUN TestGlobMatch/refs/*/main_refs/heads/main2850=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2851=== RUN TestGlobMatch/fo?_foo2852=== PAUSE TestGlobMatch/fo?_foo2853=== RUN TestGlobMatch/fo?_fo2854=== PAUSE TestGlobMatch/fo?_fo2855=== RUN TestGlobMatch/fo?_fooo2856=== PAUSE TestGlobMatch/fo?_fooo2857=== RUN TestGlobMatch/?oo_foo2858=== PAUSE TestGlobMatch/?oo_foo2859=== RUN TestGlobMatch/?oo_boo2860=== PAUSE TestGlobMatch/?oo_boo2861=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2862=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2863=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2864=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2865=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2866=== CONT TestGlobMatch/foo*bar_foobar2867=== CONT TestGlobMatch/fo?_fooo2868=== CONT TestGlobMatch/foo*bar_foo123bar2869=== CONT TestGlobMatch/fo?_fo2870=== CONT TestGlobMatch/foo_foo2871=== CONT TestGlobMatch/fo?_foo2872=== CONT TestGlobMatch/*bar_bar2873=== CONT TestGlobMatch/foo*_bar2874=== CONT TestGlobMatch/*_anything2875=== CONT TestGlobMatch/foo*_foo2876=== CONT TestGlobMatch/*_2877=== CONT TestGlobMatch/*/*_foo2878=== CONT TestGlobMatch/foo_bar2879=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2880=== CONT TestGlobMatch/foo*bar_foobarbaz2881=== CONT TestGlobMatch/?oo_boo2882=== CONT TestGlobMatch/?oo_foo2883=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2884=== CONT TestGlobMatch/refs/*/main_refs/heads/main2885=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02886=== CONT TestGlobMatch/foo*_foobar2887=== CONT TestGlobMatch/*bar_foo2888=== CONT TestGlobMatch/*bar_foobar2889=== CONT TestGlobMatch/*/*_foo/bar2890--- PASS: TestGlobMatch (0.00s)2891 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2892 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2893 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2894 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2895 --- PASS: TestGlobMatch/fo?_fo (0.00s)2896 --- PASS: TestGlobMatch/foo_foo (0.00s)2897 --- PASS: TestGlobMatch/fo?_foo (0.00s)2898 --- PASS: TestGlobMatch/*bar_bar (0.00s)2899 --- PASS: TestGlobMatch/foo*_bar (0.00s)2900 --- PASS: TestGlobMatch/*_anything (0.00s)2901 --- PASS: TestGlobMatch/foo*_foo (0.00s)2902 --- PASS: TestGlobMatch/*_ (0.00s)2903 --- PASS: TestGlobMatch/*/*_foo (0.00s)2904 --- PASS: TestGlobMatch/foo_bar (0.00s)2905 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2906 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2907 --- PASS: TestGlobMatch/?oo_boo (0.00s)2908 --- PASS: TestGlobMatch/?oo_foo (0.00s)2909 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2910 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2911 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2912 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2913 --- PASS: TestGlobMatch/*bar_foo (0.00s)2914 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2915 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)29162026/10/01 07:36:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37897/oidc2917--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)29182026/10/01 07:36:55 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232919--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)29202026/10/01 07:36:55 http: TLS handshake error from 127.0.0.1:33396: remote error: tls: bad certificate2921--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)29222026/10/01 07:36:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39975/oidc29232026/10/01 07:36:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33853/oidc2924--- PASS: TestValidateToken_Expired (0.11s)2925--- PASS: TestPins_ReservedForMatchingRule (0.11s)29262026/10/01 07:36:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42073/oidc2927--- PASS: TestValidateToken_ValidToken (0.12s)29282026/10/01 07:36:55 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45015/oidc29292026/10/01 07:36:55 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44489/oidc2930--- PASS: TestValidateToken_MultipleProviders (0.13s)29312026/10/01 07:36:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44471/oidc2932--- PASS: TestPins_TopLevelShorthand (0.16s)29332026/10/01 07:36:55 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:409812934--- PASS: TestValidateToken_KubernetesServiceAccount (0.20s)29352026/10/01 07:36:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43151/oidc2936--- PASS: TestValidateToken_BoundClaimsMismatch (0.23s)29372026/10/01 07:36:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38441/oidc29382026/10/01 07:36:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44911/oidc2939--- PASS: TestValidateToken_WrongAudience (0.24s)2940--- PASS: TestScopes_Rules (0.24s)29412026/10/01 07:36:55 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35617/oidc2942--- PASS: TestValidateToken_NoMatchingProvider (0.37s)29432026/10/01 07:36:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40213/oidc2944--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.53s)2945PASS2946Running hook tests...2947=== RUN TestSendPathsEmpty2948=== PAUSE TestSendPathsEmpty2949=== RUN TestQueueEnqueueAndFetch2950=== PAUSE TestQueueEnqueueAndFetch2951=== RUN TestQueueDeduplication2952=== PAUSE TestQueueDeduplication2953=== RUN TestQueueRemove2954=== PAUSE TestQueueRemove2955=== RUN TestQueueFetchBatchLimit2956=== PAUSE TestQueueFetchBatchLimit2957=== RUN TestQueueRetryMovesToBack2958=== PAUSE TestQueueRetryMovesToBack2959=== RUN TestQueueFetchRemoveLifecycle2960=== PAUSE TestQueueFetchRemoveLifecycle2961=== RUN TestQueueConcurrentWriters2962=== PAUSE TestQueueConcurrentWriters2963=== RUN TestQueueRemoveLargeClosure2964=== PAUSE TestQueueRemoveLargeClosure2965=== RUN TestServerClientIntegration2966=== PAUSE TestServerClientIntegration2967=== RUN TestServerQueueError2968=== PAUSE TestServerQueueError2969=== RUN TestGetListenerSocketActivation2970 server_test.go:210: === RUN TestGetListenerSocketActivation2971 --- PASS: TestGetListenerSocketActivation (0.00s)2972 PASS2973 2974--- PASS: TestGetListenerSocketActivation (0.01s)2975=== RUN TestDrainIsolatesPoisonPath2976=== PAUSE TestDrainIsolatesPoisonPath2977=== RUN TestRunNotBlockedByPoisonHead2978=== PAUSE TestRunNotBlockedByPoisonHead2979=== RUN TestDrainGivesUpWhenServerDown2980=== PAUSE TestDrainGivesUpWhenServerDown2981=== RUN TestFailedPathPrunedByLaterClosure2982=== PAUSE TestFailedPathPrunedByLaterClosure2983=== RUN TestWorkerUploadsAndRemoves2984=== PAUSE TestWorkerUploadsAndRemoves2985=== RUN TestWorkerSkipsGCdPaths2986=== PAUSE TestWorkerSkipsGCdPaths2987=== RUN TestWorkerPrunesClosureDeps2988=== PAUSE TestWorkerPrunesClosureDeps2989=== RUN TestDrainTimeout2990=== PAUSE TestDrainTimeout2991=== CONT TestSendPathsEmpty2992=== CONT TestRunNotBlockedByPoisonHead2993=== CONT TestWorkerSkipsGCdPaths2994--- PASS: TestSendPathsEmpty (0.00s)2995=== CONT TestQueueRetryMovesToBack2996=== CONT TestQueueFetchBatchLimit2997=== CONT TestQueueRemove2998=== CONT TestQueueFetchRemoveLifecycle2999=== CONT TestQueueDeduplication3000=== CONT TestQueueEnqueueAndFetch3001=== CONT TestDrainIsolatesPoisonPath3002=== CONT TestServerQueueError3003=== CONT TestFailedPathPrunedByLaterClosure3004=== CONT TestServerClientIntegration3005=== CONT TestWorkerUploadsAndRemoves3006=== CONT TestQueueRemoveLargeClosure3007=== CONT TestDrainTimeout3008=== CONT TestQueueConcurrentWriters3009=== CONT TestWorkerPrunesClosureDeps3010=== CONT TestDrainGivesUpWhenServerDown30112026/10/01 07:36:55 ERROR Failed to queue paths error="permission denied" count=13012--- PASS: TestServerQueueError (0.00s)3013--- PASS: TestServerClientIntegration (0.00s)30142026/10/01 07:36:55 INFO Uploading batch count=230152026/10/01 07:36:55 INFO Uploading batch count=130162026/10/01 07:36:55 ERROR Upload failed error="upload failed" count=130172026/10/01 07:36:55 INFO Upload queue status pending=230182026/10/01 07:36:55 INFO Upload queue status pending=230192026/10/01 07:36:55 INFO Uploading batch count=130202026/10/01 07:36:55 INFO Uploading batch count=230212026/10/01 07:36:55 INFO Upload queue status pending=230222026/10/01 07:36:55 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3429646391/002/nonexistent30232026/10/01 07:36:55 INFO Upload queue status pending=330242026/10/01 07:36:55 INFO Uploading batch count=130252026/10/01 07:36:55 ERROR Upload failed error="upload failed" count=13026--- PASS: TestQueueRemove (0.02s)30272026/10/01 07:36:55 INFO Uploading batch count=13028--- PASS: TestQueueFetchBatchLimit (0.02s)30292026/10/01 07:36:55 INFO Uploading batch count=430302026/10/01 07:36:55 ERROR Upload failed error="upload failed" count=430312026/10/01 07:36:55 INFO Uploading batch count=23032--- PASS: TestQueueEnqueueAndFetch (0.02s)30332026/10/01 07:36:55 ERROR Upload failed error="upload failed" count=230342026/10/01 07:36:55 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4231334988/002/a30352026/10/01 07:36:55 INFO Uploading batch count=130362026/10/01 07:36:55 INFO Uploading batch count=130372026/10/01 07:36:55 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath898518830/002/bbb30382026/10/01 07:36:55 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4231334988/002/b3039--- PASS: TestQueueDeduplication (0.02s)3040--- PASS: TestQueueFetchRemoveLifecycle (0.02s)30412026/10/01 07:36:55 INFO Uploading batch count=230422026/10/01 07:36:55 ERROR Upload failed error="upload failed" count=230432026/10/01 07:36:55 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4231334988/002/c3044--- PASS: TestQueueRetryMovesToBack (0.02s)30452026/10/01 07:36:55 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4231334988/002/d30462026/10/01 07:36:55 INFO Uploading batch count=230472026/10/01 07:36:55 ERROR Upload failed error="upload failed" count=230482026/10/01 07:36:55 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4231334988/002/e30492026/10/01 07:36:55 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4231334988/002/f30502026/10/01 07:36:55 INFO Uploading batch count=130512026/10/01 07:36:55 ERROR Upload failed error="upload failed" count=130522026/10/01 07:36:55 ERROR Drain finished with paths left in queue remaining=103053--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)30542026/10/01 07:36:55 INFO Uploading batch count=130552026/10/01 07:36:55 ERROR Upload failed error="upload failed" count=130562026/10/01 07:36:55 INFO Uploading batch count=13057--- PASS: TestDrainGivesUpWhenServerDown (0.02s)30582026/10/01 07:36:55 ERROR Upload failed error="upload failed" count=130592026/10/01 07:36:55 ERROR Drain finished with paths left in queue remaining=13060--- PASS: TestDrainIsolatesPoisonPath (0.02s)3061--- PASS: TestWorkerSkipsGCdPaths (0.03s)3062--- PASS: TestWorkerPrunesClosureDeps (0.03s)3063--- PASS: TestWorkerUploadsAndRemoves (0.03s)3064--- PASS: TestQueueRemoveLargeClosure (0.11s)3065--- PASS: TestQueueConcurrentWriters (0.16s)30662026/10/01 07:36:56 ERROR Upload failed error="context deadline exceeded" count=230672026/10/01 07:36:56 ERROR Drain finished with paths left in queue remaining=43068--- PASS: TestDrainTimeout (0.21s)30692026/10/01 07:36:56 INFO Uploading batch count=130702026/10/01 07:36:56 INFO Uploading batch count=130712026/10/01 07:36:56 INFO Uploading batch count=130722026/10/01 07:36:56 ERROR Upload failed error="upload failed" count=130732026/10/01 07:36:56 INFO Uploading batch count=130742026/10/01 07:36:56 ERROR Upload failed error="upload failed" count=130752026/10/01 07:36:56 INFO Uploading batch count=130762026/10/01 07:36:56 ERROR Upload failed error="upload failed" count=130772026/10/01 07:36:56 INFO Uploading batch count=130782026/10/01 07:36:56 ERROR Upload failed error="upload failed" count=130792026/10/01 07:36:56 ERROR Drain finished with paths left in queue remaining=13080--- PASS: TestRunNotBlockedByPoisonHead (1.03s)3081PASS

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #290 · raw

succeeded `niks3-go-unit-tests` `checks.aarch64-linux.go-unit-tests` · build #290 · raw