ztunnel icon indicating copy to clipboard operation
ztunnel copied to clipboard

Published 20 hours ago • verified publisher icon istio

Failure to do `apk update` when ambient captured from wolfi pods

Open howardjohn opened this issue 1 year ago • 2 comments 

/ $apk update
fetch https://packages.wolfi.dev/os/x86_64/APKINDEX.tar.gz
WARNING: updating and opening https://packages.wolfi.dev/os: IO ERROR
2 unavailable, 0 stale; 27 distinct packages available

howardjohn avatar Jul 05 '24 16:07 howardjohn

ERROR

2024-07-05T17:45:46.516241Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: loop
2024-07-05T17:45:46.516258Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: read err=false
2024-07-05T17:45:46.516277Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: write 256
2024-07-05T17:45:46.516297Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: wrote 256/256
2024-07-05T17:45:46.516309Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: loop
2024-07-05T17:45:46.516323Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: read err=false
2024-07-05T17:45:46.516340Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: write 256
2024-07-05T17:45:46.516369Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: wrote 256/256
2024-07-05T17:45:46.516391Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: loop
2024-07-05T17:45:46.516414Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: read err=false
2024-07-05T17:45:46.516436Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: write 256
2024-07-05T17:45:46.516496Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: wrote 256/256
2024-07-05T17:45:46.516514Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: loop
2024-07-05T17:45:46.516528Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: read err=false
2024-07-05T17:45:46.516542Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     howardjohn: write 256
2024-07-05T17:45:46.516590Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     io terminated ungracefully      err=Connection reset by peer (os error 104)
2024-07-05T17:45:46.516634Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     receive res=Ok(0)
2024-07-05T17:45:46.516665Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:receive     failed to shutdown peer, they already shutdown  err=Transport endpoint is not connected (os error 107)
2024-07-05T17:45:46.516730Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:send        howardjohn: loop
2024-07-05T17:45:46.516753Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:send        howardjohn: read err=false
2024-07-05T17:45:46.516767Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:send        howardjohn: write 24
2024-07-05T17:45:46.516870Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:send        howardjohn: wrote 24/24
2024-07-05T17:45:46.516906Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:send        howardjohn: loop
2024-07-05T17:45:46.516931Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:send        howardjohn: read err=false
2024-07-05T17:45:46.516956Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:send        howardjohn: read empty
2024-07-05T17:45:46.516978Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}:send        send    res=Ok(660)
2024-07-05T17:45:46.517085Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=c6f65b42f7665bfb56eea5a7ecfffb39}     copy complete   sent=660 received=0



2024-07-05T17:46:00.096457Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.096472Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read err=false
2024-07-05T17:46:00.096496Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: write 256
2024-07-05T17:46:00.096522Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: wrote 256/256
2024-07-05T17:46:00.096534Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.096546Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read err=false
2024-07-05T17:46:00.096560Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: write 256
2024-07-05T17:46:00.096578Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: wrote 256/256
2024-07-05T17:46:00.096592Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.096606Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read err=false
2024-07-05T17:46:00.096623Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: write 256
2024-07-05T17:46:00.096655Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: wrote 256/256
2024-07-05T17:46:00.096674Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.096694Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read err=false
2024-07-05T17:46:00.096706Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: write 256
2024-07-05T17:46:00.096725Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: wrote 256/256
2024-07-05T17:46:00.096737Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.096750Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read err=false
2024-07-05T17:46:00.096767Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: write 256
2024-07-05T17:46:00.096799Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: wrote 256/256
2024-07-05T17:46:00.096814Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.096832Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read err=false
2024-07-05T17:46:00.096853Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: write 248
2024-07-05T17:46:00.096878Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: wrote 248/248
2024-07-05T17:46:00.096890Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.096924Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: loop
2024-07-05T17:46:00.098385Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: loop
2024-07-05T17:46:00.098449Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: read err=false
2024-07-05T17:46:00.098463Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: write 24
2024-07-05T17:46:00.098548Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: wrote 24/24
2024-07-05T17:46:00.098564Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: loop
2024-07-05T17:46:00.098587Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.099508Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.099570Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: loop
2024-07-05T17:46:00.099588Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: read err=false
2024-07-05T17:46:00.099607Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: read empty
2024-07-05T17:46:00.099631Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        send    res=Ok(660)
2024-07-05T17:46:00.111931Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.112060Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read err=false
2024-07-05T17:46:00.112075Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read empty
2024-07-05T17:46:00.112094Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     receive res=Ok(5085883)
2024-07-05T17:46:00.112200Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}     copy complete   sent=660 received=5085883

SUCCESS

2024-07-05T17:46:00.096706Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: write 256
2024-07-05T17:46:00.096725Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: wrote 256/256
2024-07-05T17:46:00.096737Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.096750Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read err=false
2024-07-05T17:46:00.096767Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: write 256
2024-07-05T17:46:00.096799Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: wrote 256/256
2024-07-05T17:46:00.096814Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.096832Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read err=false
2024-07-05T17:46:00.096853Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: write 248
2024-07-05T17:46:00.096878Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: wrote 248/248
2024-07-05T17:46:00.096890Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.096924Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: loop
2024-07-05T17:46:00.098385Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: loop
2024-07-05T17:46:00.098449Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: read err=false
2024-07-05T17:46:00.098463Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: write 24
2024-07-05T17:46:00.098548Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: wrote 24/24
2024-07-05T17:46:00.098564Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: loop
2024-07-05T17:46:00.098587Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.099508Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.099570Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: loop
2024-07-05T17:46:00.099588Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: read err=false
2024-07-05T17:46:00.099607Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        howardjohn: read empty
2024-07-05T17:46:00.099631Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:send        send    res=Ok(660)
2024-07-05T17:46:00.111931Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: loop
2024-07-05T17:46:00.112060Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read err=false
2024-07-05T17:46:00.112075Z     error   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     howardjohn: read empty
2024-07-05T17:46:00.112094Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}:receive     receive res=Ok(5085883)
2024-07-05T17:46:00.112200Z     trace   copy:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}     copy complete   sent=660 received=5085883
2024-07-05T17:46:00.112320Z     info    access  connection complete     src.addr=shell-56bd5dbdbf-2h248:53178 src.workload="shell-56bd5dbdbf-2h248" src.namespace="default" dst.addr=34.160.111.32:443 direction="outbound" bytes_sent=660 bytes_recv=5085883 duration="2000ms"
2024-07-05T17:46:00.112407Z     debug   proxy::outbound:proxy{wl=default/shell-56bd5dbdbf-2h248}:outbound{id=6fe92378ea6ca6639c102c02a8368966}  connection completed    component="outbound" dur=2.001219576s

It seems like the client (apk) is just disconnecting before it reads everything, but I don't know why it would do that

howardjohn avatar Jul 05 '24 17:07 howardjohn

Good strace:

read(7, "#C\246\370l\320\nW\366\253\202\t\203\273^\10\tDv\333Q4\243t\316\373-\361\332\335\314\235"..., 2486) = 256
read(7, "\37\211\n\257\350=\326w\223[\5}\263\206\16\240CT\231\0\257\266\247\21O\376Hp\362\205\301\231"..., 2230) = 256
read(7, "\246'\365\370\205 i\253<\277\334\227\254\353\276\26\255\t\355\200i\346nq\221\3422\350\31s\273\373"..., 1974) = 256
read(7, "\2DE[\35g/\230J-\r\30\17\265\316\253\350\310%R\324\224\265*\2005B^\320\250\350\236"..., 1718) = 256
read(7, "\246iC\26N\240L\317\236oc:\271t\346\320*\7\226\232\31_\1\337\3lst.\315\273!"..., 1462) = 256
read(7, "\233\27\245\255\344q\37\372\331\22\376\366p\345OE\341^q\372tu\323E\325<\302\v>\213\355y"..., 1206) = 256
read(7, "\263\305\275\213\314\4\344=\25\360?\316\17\346r2\3029\227\3716j\324\325\361/\204\277)Ro\302"..., 950) = 256
read(7, "\356\317\343\333\200\221\32(\272\3\331SH\204'W\216\256-p@\205\364m\322\363\5\376\355\274,\345"..., 694) = 256
read(7, "\2115\233#\331\351\0227`\354g\22\374(\206AvC6\201sd\5\262\215\334\272\203\373A\315\10"..., 438) = 256
read(7, "\32\252\321\10\246\274r\1\t\260\352ex\261\261R\242\4\216\333(\363\263\372\356$\217\0\324G$\305"..., 182) = 182
write(8, "\212\245\233\353\230C\274\0\345\304@B\263H\342X\226\7\375\217\252cL'\320\27f\30\321\242\17\37"..., 76460) = 76460
write(7, "\27\3\3\0\23\252\332\204\\\212\344=,NH\324\310\325\361Plk1\372", 24) = 24
close(7)                                = 0
brk(0x5ba5e907c000)                     = 0x5ba5e907c000
close(8)                                = 0

Bad strace:

read(7, "\27\3\3\5s", 5)                = 5
read(7, "\250P\237\365\177[`\304*\275L\316\217\23s\265\212\2340\277\214\0064P\364\322\177\356\321\20\27v"..., 1395) = 1395
read(7, "\27\3\3\5s", 5)                = 5
read(7, "9\277\227^t\201\375\207\374\v\236\225l\3642\\\210Vnp\313\32\344u?\337//ccCb"..., 1395) = 1395
read(7, "\27\3\3\5s", 5)                = 5
read(7, "\10U\350,IP\27?P\302\375Gi\254OM\324d\3777T\35\227\340\355j+\372)l\17s"..., 1395) = 1395
read(7, "\27\3\3\5s", 5)                = 5
read(7, "\366\203N\260\371m\27\256\217\354a8\371\341\324\1'\27D\0\333\253\315\30pui\222\355\214\305\27"..., 1395) = 1395
read(7, "\27\3\3\5s", 5)                = 5
read(7, "c\22\317\27\214\200~\335\272\305x.t\242\236\300\327)\317\240T{\24\332\246\314eJ(\23\306\205"..., 1395) = 1395
read(7, "\27\3\3\5s", 5)                = 5
read(7, "\200\270\30\3530\217\325_A\256\375^\260saX\314\300\305bZ\306ma\300f\247\"\217t\215\362"..., 1395) = 1395
read(7, "\27\3\3\5s", 5)                = 5
read(7, "\t\2649_V}\250\275\3333O>he\347\0\331(5\361\25\20\4\22\270r\375x\33\324\266m"..., 1395) = 1395
read(7, "\27\3\3\5s", 5)                = 5
read(7, "\353\360\7}\310$\235\26\357)\253 \235\343\177\7\301m\257\227u?s\352\21\247I\201\331\316\300'"..., 1395) = 1395
write(7, "\27\3\3\0\23\374[\362\352\370\235\332\16\323'\266\f{\211\303T\344o5", 24) = 24
write(8, "\321\307*Z \372X\325\350*\372XE\276\212>V\220Cz|\25}\254x)P\4+\264M\330"..., 34474) = 34474
close(7)                                = 0
brk(0x5c377decd000)                     = 0x5c377decd000
close(8)                                = 0

Again, it just looks like the client (apk) decides it is done and sends a tls close_alert then closes the connection... It does so in both cases, just in the failure case it does so before the entire payload is downloaded

howardjohn avatar Jul 05 '24 17:07 howardjohn

Any news on this? I am facing this issue when run command apk add perl

laiminhtrung1997 avatar Aug 01 '24 09:08 laiminhtrung1997

No, I haven't been able to track this down. The only thing I have seen with the issue is in apk and I don't have a clear picture of what is triggering it.

howardjohn avatar Aug 01 '24 15:08 howardjohn

Is there any workaround for this? I didn't have the issue when I used istio 1.22.3.

laiminhtrung1997 avatar Aug 01 '24 16:08 laiminhtrung1997

I do not know of a workaround since I am not sure of the root cause. I did notice if I just did the apk call a few times it would succeed.

howardjohn avatar Aug 01 '24 16:08 howardjohn

I'm assuming this is not affected by DNS proxying on/off at all?

bleggett avatar Aug 01 '24 17:08 bleggett

Also https://github.com/gliderlabs/docker-alpine/issues/348 is suspiciously similar.

bleggett avatar Aug 01 '24 17:08 bleggett

I don't recall if I had DNS on or not. Maybe that would explain why I didn't see anything, it fails to do a UDP dns lookup (missed by my inspection of only tcp??) and aborts or something perhaps

howardjohn avatar Aug 01 '24 17:08 howardjohn

I struggle to think of what else would cause it, unless

1 apk has REALLY weird behaviors, regardless of the container you run it in. 2. There's something unique about running ambient + apk in a wolfi container (which smells like local DNS quirk to me somehow)

bleggett avatar Aug 01 '24 17:08 bleggett

Did a lot more investigation:

  • Happens on wolfi and alpine. curl of the same URL works 100% of the time. This to me strongly suspects the issue lies in the behavior of apk as a network client (that doesn't mean its their fault, but their behavior exposes the issue at least)
  • They have 2 backends, but the ones I am hitting/are usually used is their handmade 'libfetch' library. I tried to trace this down a lot more but struggled a bit. I am like 20% sure the error ("EIO" internally) actually comes from apk_tar_parse maybe.

My suspicion is this actually has to do with some chunking. They have some code in there that seems to expect to get a chunk of EXACTLY 512 bytes on read calls, and bail out if not so -- while a proper client would continue reading until a read()=0 and buffer as needed. I am not certain that is the case since the code is 95% inscrutable though.

I've tested without our buffer resizing as well as some different buffer sizes. oddly, it did seem like changing the buffer to be smaller helped a bit, but then I couldn't reproduce it later, so may be a network timing thing (eventually I am going to get marked as a spammer and get rate limited I fear :grimacing: ).

Plain old tokio::io::copy_bidirectional doesn't suffer from this.

So next plausible steps would be:

  • Try to get a better apk environment with a real debugger with symbols running so we can more clearly see whatis going on from that perspective
  • Slowly tweak tokio::io::copy_bidirectional until it fails

howardjohn avatar Aug 02 '24 00:08 howardjohn 

fetch https://dl-cdn.alpinelinux.org/alpine/v3.18/main/x86_64/APKINDEX.tar.gz
fetch https://dl-cdn.alpinelinux.org/alpine/v3.18/community/x86_64/APKINDEX.tar.gz
WARNING: updating and opening https://dl-cdn.alpinelinux.org/alpine/v3.18/community: IO ERROR
(1/2) Installing libbz2 (1.0.8-r5)
(2/2) Installing perl (5.36.2-r0)
ERROR: Failed to create usr/lib/perl5/core_perl/CORE/libperl.so: Connection aborted
ERROR: perl-5.36.2-r0: IO ERROR
1 error; 7 MiB in 16 packages

It is still failed. I use the latest build from Friday. 1.24-alpha.ecb53cb6a199ed502833ef2eadf1b42b15bea381

laiminhtrung1997 avatar Aug 04 '24 04:08 laiminhtrung1997

That commit doesn't have the fix, need https://github.com/istio/istio/commit/89f238db461771a1b2288addb5a0f64761ffb23c

howardjohn avatar Aug 04 '24 13:08 howardjohn