fn deploy is not invalidating previous image

[rdallman]

In gitlab by @carimura on Jul 16, 2017, 21:04

1. run my license plate pipeline
2. watch plates come up with yellow boxes around plates
3. change draw func to draw red box instead of yellow
4. run again, still yellow
5. kubectl scale down to 0, then back up to 30
6. run again, now red

also here's some interesting output:

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hello Thomas

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hi!

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hello Thomas Demo

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hi!

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hello Thomas

and the logs for those certainly indicate that I should be getting the same version (0.0.2) .. wonkiness:

fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:10Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XRTF07WGY00000000000 image="carimura/hello:0.0.2" name=run.myapp.requests route="/hello" type=count value=1
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:10Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XRTF07WGY00000000000 image="carimura/hello:0.0.2" name=run.myapp.waittime route="/hello" type=time value=0s
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:11Z" level=info msg="container status" action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XRTF07WGY00000000000 container_error= container_finished=2017-07-17 20:13:11.159124686 +0000 UTC container_running=false container_status=exited exit_code=0 image="carimura/hello:0.0.2" route="/hello"
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:11Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XRTF07WGY00000000000 image="carimura/hello:0.0.2" name=run.myapp.succeeded route="/hello" type=count value=1
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:11Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XRTF07WGY00000000000 image="carimura/hello:0.0.2" name=run.myapp.time route="/hello" type=time value=359.019267ms
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:11Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XRTF07WGY00000000000 image="carimura/hello:0.0.2" name="run.exec_time" route="/hello" type=time value=359.019267ms
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:12Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XT5V07WH200000000000 image="carimura/hello:0.0.2" name=run.myapp.requests route="/hello" type=count value=1
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:12Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XT5V07WH200000000000 image="carimura/hello:0.0.2" name=run.myapp.waittime route="/hello" type=time value=0s
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:13Z" level=info msg="container status" action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XT5V07WH200000000000 container_error= container_finished=2017-07-17 20:13:13.142631114 +0000 UTC container_running=false container_status=exited exit_code=0 image="carimura/hello:0.0.2" route="/hello"
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:13Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XT5V07WH200000000000 image="carimura/hello:0.0.2" name=run.myapp.succeeded route="/hello" type=count value=1
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:13Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XT5V07WH200000000000 image="carimura/hello:0.0.2" name=run.myapp.time route="/hello" type=time value=1.31405758s
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:13Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92XT5V07WH200000000000 image="carimura/hello:0.0.2" name="run.exec_time" route="/hello" type=time value=1.31405758s
fn-api-deployment-2577755329-tbcb3 fn-api time="2017-07-17T20:13:32Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YDH807WGY00000000000 image="carimura/hello:0.0.2" name=run.myapp.requests route="/hello" type=count value=1
fn-api-deployment-2577755329-tbcb3 fn-api time="2017-07-17T20:13:32Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YDH807WGY00000000000 image="carimura/hello:0.0.2" name=run.myapp.waittime route="/hello" type=time value=0s
fn-api-deployment-2577755329-tbcb3 fn-api time="2017-07-17T20:13:33Z" level=info msg="container status" action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YDH807WGY00000000000 container_error= container_finished=2017-07-17 20:13:33.542690037 +0000 UTC container_running=false container_status=exited exit_code=0 image="carimura/hello:0.0.2" route="/hello"
fn-api-deployment-2577755329-tbcb3 fn-api time="2017-07-17T20:13:33Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YDH807WGY00000000000 image="carimura/hello:0.0.2" name=run.myapp.succeeded route="/hello" type=count value=1
fn-api-deployment-2577755329-tbcb3 fn-api time="2017-07-17T20:13:33Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YDH807WGY00000000000 image="carimura/hello:0.0.2" name=run.myapp.time route="/hello" type=time value=383.260975ms
fn-api-deployment-2577755329-tbcb3 fn-api time="2017-07-17T20:13:33Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YDH807WGY00000000000 image="carimura/hello:0.0.2" name="run.exec_time" route="/hello" type=time value=383.260975ms
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:35Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YGNR07WH400000000000 image="carimura/hello:0.0.2" name=run.myapp.requests route="/hello" type=count value=1
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:35Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YGNR07WH400000000000 image="carimura/hello:0.0.2" name=run.myapp.waittime route="/hello" type=time value=0s
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:36Z" level=info msg="container status" action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YGNR07WH400000000000 container_error= container_finished=2017-07-17 20:13:36.178229742 +0000 UTC container_running=false container_status=exited exit_code=0 image="carimura/hello:0.0.2" route="/hello"
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:36Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YGNR07WH400000000000 image="carimura/hello:0.0.2" name=run.myapp.succeeded route="/hello" type=count value=1
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:36Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YGNR07WH400000000000 image="carimura/hello:0.0.2" name=run.myapp.time route="/hello" type=time value=1.31657387s
fn-api-deployment-2577755329-12x1d fn-api time="2017-07-17T20:13:36Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YGNR07WH400000000000 image="carimura/hello:0.0.2" name="run.exec_time" route="/hello" type=time value=1.31657387s
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:38Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YKZT07WH000000000000 image="carimura/hello:0.0.2" name=run.myapp.requests route="/hello" type=count value=1
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:38Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YKZT07WH000000000000 image="carimura/hello:0.0.2" name=run.myapp.waittime route="/hello" type=time value=0s
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:39Z" level=info msg="container status" action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YKZT07WH000000000000 container_error= container_finished=2017-07-17 20:13:38.966769682 +0000 UTC container_running=false container_status=exited exit_code=0 image="carimura/hello:0.0.2" route="/hello"
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:39Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YKZT07WH000000000000 image="carimura/hello:0.0.2" name=run.myapp.succeeded route="/hello" type=count value=1
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:39Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YKZT07WH000000000000 image="carimura/hello:0.0.2" name=run.myapp.time route="/hello" type=time value=369.45599ms
fn-api-deployment-2577755329-8shth fn-api time="2017-07-17T20:13:39Z" level=info action="server.handleRunnerRequest)-fm" app=myapp call_id=01BN92YKZT07WH000000000000 image="carimura/hello:0.0.2" name="run.exec_time" route="/hello" type=time value=369.45599ms

[rdallman]

In gitlab by @carimura on Jul 16, 2017, 21:05

changed the description

[rdallman]

In gitlab by @carimura on Jul 16, 2017, 21:05

changed the description

[rdallman]

In gitlab by @carimura on Jul 17, 2017, 12:05

maybe title is misleading basically I'm observing old code running after fn deploy. it's spotty. can't tell if it's some pods not getting updated, etc.

[rdallman]

In gitlab by @carimura on Jul 17, 2017, 13:14

changed the description

[rdallman]

In gitlab by @carimura on Jul 19, 2017, 20:25

@treeder @rdallman @denismakogon this one is urgent... it's using old images and it stops my ability to demo / work on the demo. You can see my logs are pulling two different versions of the same function:

fn-api-deployment-2577755329-dp2pg fn-api time="2017-07-20T03:13:05Z" level=info msg="libdc1394 error: Failed to initialize libdc1394
fn-api-deployment-2577755329-dp2pg fn-api " app_name=myapp call_id=01BNEZQX7107WJE00000000000 image="carimura/detect-plates:0.0.32" path= runner=async user_log=true
fn-api-deployment-2577755329-dp2pg fn-api time="2017-07-20T03:13:05Z" level=info msg="5 :  [1,"Sent","15005203859441916"]
fn-api-deployment-2577755329-dp2pg fn-api " app_name=myapp call_id=01BNEZQX7107WJE00000000000 image="carimura/detect-plates:0.0.32" path= runner=async user_log=true
fn-api-deployment-2577755329-w29rd fn-api time="2017-07-20T03:13:05Z" level=info msg="
fn-api-deployment-2577755329-w29rd fn-api " app_name=myapp call_id=01BNEZQWR607WJ000000000000 image="carimura/detect-plates:prod-29576c963a56856e4892b5ef1b566f515c3c8fe9" path= runner=async user_log=true
fn-api-deployment-2577755329-w29rd fn-api time="2017-07-20T03:13:05Z" level=info msg="
fn-api-deployment-2577755329-w29rd fn-api " app_name=myapp call_id=01BNEZQWR607WJ000000000000 image="carimura/detect-plates:prod-29576c963a56856e4892b5ef1b566f515c3c8fe9" path= runner=async user_log=true
fn-api-deployment-2577755329-w29rd fn-api time="2017-07-20T03:13:06Z" level=info msg=" FOUND PLATE ------> {RequestedTopN:10 BestPlate:27Z592 TopNPlates:[{Characters:27Z592 OverallConfidence:87.007126 MatchesTemplate:false} {Characters:Z7Z592 OverallConfidence:86.66267 MatchesTemplate:false} {Characters:Z27Z592 OverallConfidence:85.34955 MatchesTemplate:false} {Characters:ZZ7Z592 OverallConfidence:85.00509 MatchesTemplate:false} {Characters:227Z592 OverallConfidence:83.92249 MatchesTemplate:false} {Characters:E27Z592 OverallConfidence:83.78511 MatchesTemplate:false} {Characters:2Z7Z592 OverallConfidence:83.57803 MatchesTemplate:false} {Characters:EZ7Z592 OverallConfidence:83.44064 MatchesTemplate:false} {Characters:7Z592 OverallConfidence:82.13487 MatchesTemplate:false} {Characters:87Z592 OverallConfidence:79.175835 MatchesTemplate:false}] ProcessingTimeMs:628.9003 PlatePoints:[{X:101 Y:373} {X:174 Y:374} {X:173 Y:413} {X:101 Y:412}] PlateIndex:0 RegionConfidence:0 Region:}6 :  [1,"Sent","15005203860705855"]

[rdallman]

In gitlab by @carimura on Jul 19, 2017, 20:25

i even killed the whole k8s cluster and brought it back up, still same issue.... can't deploy cause uses old version.

[rdallman]

In gitlab by @treeder on Jul 19, 2017, 20:30

Can you paste all the commands you're using here?

Are you bumping the version? are you deploying after you bump the version? etc.

[rdallman]

In gitlab by @carimura on Jul 19, 2017, 20:33

yes. it happens when i use fn deploy and bump the version, or wercker and it uses git commits. Take a look at those logs above. Can you explain a case where the same function would run two different versions right after one another?

[rdallman]

In gitlab by @treeder on Jul 19, 2017, 20:34

Aggh, think I see why. There's a route cache that appears to never expire (Seif added this). So probably works fine on single server, doesn't sync up across multiple servers.

Give me a few, I'll either remove it or change it to an expiring cache (like 30 seconds or something).

[rdallman]

In gitlab by @carimura on Jul 19, 2017, 20:36

ok great. i'm not crazy.

~/workspace/hello 15s
❯ curl http://localhost:8080/r/myapp/hello
Hello Yodel and Chad

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hello Yodel and Chad

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hello Yodel and Chad

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hello Yodel and Chad

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hello Yodel and Chad

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hello Chad

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hello Yodel

~/workspace/hello
❯ curl http://localhost:8080/r/myapp/hello
Hello Chad

[rdallman]

In gitlab by @treeder on Jul 19, 2017, 22:11

mentioned in commit 2d7672e1404cbc5136d8ea0f16b727ab9e75e9dd

[rdallman]

In gitlab by @derekschultz on Jul 20, 2017, 08:44

closed via commit 0879fce4ce3332cbfe4bed43f2d4a1f81096fc45

[rdallman]

In gitlab by @derekschultz on Jul 20, 2017, 08:44

closed via merge request !116

[rdallman]

In gitlab by @derekschultz on Jul 20, 2017, 09:19

mentioned in commit 0879fce4ce3332cbfe4bed43f2d4a1f81096fc45

[rdallman]

In gitlab by @carimura on Jul 22, 2017, 10:08

Ok I found this in a different place now... if you delete a route, and then do another fn init, it restarts the versioning back at 1, but the old code still sits on the servers so it pulls old code.

Re-opening ticket. I think an fn deploy should always invalidate the old image.... is this possible?

[rdallman]

In gitlab by @carimura on Jul 22, 2017, 10:08

reopened

[rdallman]

In gitlab by @treeder on Jul 23, 2017, 13:55

Another way to do this is to check Docker Hub (or whatever registry) and start the version after the most recent one, then they don't overwrite their functions in the registry either. Here's one way to check:

curl -L -s 'https://registry.hub.docker.com/v2/repositories/treeder/hello-go/tags?page_size=10'\ | jq '."results"[]["name"]'

[rdallman]

In gitlab by @carimura on Jul 23, 2017, 14:17

fyi I'll keep this one open, but it's not critical because the "delete your func file" might not be common...

[carimura]

closing for now....