[Bug] Update function using package manager response 400 Bad Request

truong-hua commented 8 months ago

Search before asking

[X] I searched in the issues and found nothing similar.

Version

2.11.3

Minimal reproduce step

Create a function using package from package manager
Update the function (ex: change parallelism from 1 to 2)

Example payload:

------WebKitFormBoundary6hEdIldTcUATSkDo
Content-Disposition: form-data; name="functionConfig"; filename="blob"
Content-Type: application/json

{"parallelism":1,"cleanupSubscription":true}
------WebKitFormBoundary6hEdIldTcUATSkDo--

What did you expect to see?

Response 200 and function successfully updated

What did you see instead?

Response 400 with error:

{
    "reason": "Invalid stream name : 'Invalid log name \"/function://public/default/package-pulsar@82804.0\" caused by empty node name specified @11'"
}

Anything else?

This does not happen when update a function which is not using package from package manager (package manager disabled)

Are you willing to submit a PR?

[ ] I'm willing to submit a PR!

Technoboy- commented 8 months ago

@jiangpengcheng Could you help for this ?

jiangpengcheng commented 8 months ago

I couldn't reproduce this error with 2.11.3:

I have no name!@sn-platform-pulsar-broker-0:/pulsar$ ./bin/pulsar-admin packages upload function://public/default/java-function@1.0 --path /pulsar/examples/api-examples.jar --description java-function@1.0
The package 'function://public/default/java-function@1.0' uploaded from path '/pulsar/examples/api-examples.jar' successfully
I have no name!@sn-platform-pulsar-broker-0:/pulsar$ bin/pulsar-admin functions create --jar function://public/default/java-function@1.0 --name package-java-fn --className org.apache.pulsar.functions.api.examples.ExclamationFunction --inputs persistent://public/default/package-java-fn-input --output persistent://public/default/package-java-fn-output --cpu 0.1 --log-topic persistent://public/default/package-java-fn-logs
Created successfully
I have no name!@sn-platform-pulsar-broker-0:/pulsar$
I have no name!@sn-platform-pulsar-broker-0:/pulsar$ bin/pulsar-admin functions update --name package-java-fn --cpu 0.2
Updated successfully
I have no name!@sn-platform-pulsar-broker-0:/pulsar$ bin/pulsar-admin functions update --name package-java-fn --parallelism 2
Updated successfully
I have no name!@sn-platform-pulsar-broker-0:/pulsar$

This 400 error seems to be caused by the bookkeeper, could you paste the related logs of the broker and bookkeeper? @truong-hua

truong-hua commented 8 months ago

hi @jiangpengcheng, there is no bookeeper error logs related. Btw, there is a stacktrace from pulsar-worker service

2024-01-22T10:41:35,039+0000 [function-web-61-4] INFO  org.apache.pulsar.functions.worker.WorkerUtils - Downloading function://public/default/com-doopage-pulsar@82804.0 from BK...,
2024-01-22T10:41:35,039+0000 [function-web-61-4] ERROR org.apache.pulsar.functions.worker.rest.api.FunctionsImpl - Invalid update Function request @ /public/ticdc/test-fn,
org.apache.distributedlog.exceptions.InvalidStreamNameException: Invalid stream name : 'Invalid log name "/function://public/default/com-doopage-pulsar@82804.0" caused by empty node name specified @11',
    at org.apache.distributedlog.util.DLUtils.validatePathName(DLUtils.java:359) ~[org.apache.distributedlog-distributedlog-core-4.15.5.jar:4.15.5],
    at org.apache.distributedlog.util.DLUtils.validateAndNormalizeName(DLUtils.java:296) ~[org.apache.distributedlog-distributedlog-core-4.15.5.jar:4.15.5],
    at org.apache.distributedlog.BKDistributedLogNamespace.openLog(BKDistributedLogNamespace.java:185) ~[org.apache.distributedlog-distributedlog-core-4.15.5.jar:4.15.5],
    at org.apache.distributedlog.BKDistributedLogNamespace.openLog(BKDistributedLogNamespace.java:172) ~[org.apache.distributedlog-distributedlog-core-4.15.5.jar:4.15.5],
    at org.apache.pulsar.functions.worker.WorkerUtils.downloadFromBookkeeper(WorkerUtils.java:123) ~[org.apache.pulsar-pulsar-functions-worker-2.11.3.jar:2.11.3],
    at org.apache.pulsar.functions.worker.WorkerUtils.downloadFromBookkeeper(WorkerUtils.java:116) ~[org.apache.pulsar-pulsar-functions-worker-2.11.3.jar:2.11.3],
    at org.apache.pulsar.functions.worker.rest.api.FunctionsImpl.updateFunction(FunctionsImpl.java:372) ~[org.apache.pulsar-pulsar-functions-worker-2.11.3.jar:2.11.3],
    at org.apache.pulsar.functions.worker.rest.api.v3.FunctionsApiV3Resource.updateFunction(FunctionsApiV3Resource.java:91) ~[org.apache.pulsar-pulsar-functions-worker-2.11.3.jar:2.11.3],
    at jdk.internal.reflect.GeneratedMethodAccessor366.invoke(Unknown Source) ~[?:?],
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?],
    at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?],
    at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:124) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:167) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$VoidOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:159) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:79) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:475) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:397) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:81) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:255) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) ~[org.glassfish.jersey.core-jersey-common-2.34.jar:?],
    at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) ~[org.glassfish.jersey.core-jersey-common-2.34.jar:?],
    at org.glassfish.jersey.internal.Errors.process(Errors.java:292) ~[org.glassfish.jersey.core-jersey-common-2.34.jar:?],
    at org.glassfish.jersey.internal.Errors.process(Errors.java:274) ~[org.glassfish.jersey.core-jersey-common-2.34.jar:?],
    at org.glassfish.jersey.internal.Errors.process(Errors.java:244) ~[org.glassfish.jersey.core-jersey-common-2.34.jar:?],
    at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) ~[org.glassfish.jersey.core-jersey-common-2.34.jar:?],
    at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:234) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:680) ~[org.glassfish.jersey.core-jersey-server-2.34.jar:?],
    at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394) ~[org.glassfish.jersey.containers-jersey-container-servlet-core-2.34.jar:?],
    at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346) ~[org.glassfish.jersey.containers-jersey-container-servlet-core-2.34.jar:?],
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:366) ~[org.glassfish.jersey.containers-jersey-container-servlet-core-2.34.jar:?],
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:319) ~[org.glassfish.jersey.containers-jersey-container-servlet-core-2.34.jar:?],
    at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205) ~[org.glassfish.jersey.containers-jersey-container-servlet-core-2.34.jar:?],
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[org.eclipse.jetty-jetty-servlet-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656) ~[org.eclipse.jetty-jetty-servlet-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.servlets.QoSFilter.doFilter(QoSFilter.java:202) ~[org.eclipse.jetty-jetty-servlets-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[org.eclipse.jetty-jetty-servlet-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626) ~[org.eclipse.jetty-jetty-servlet-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552) ~[org.eclipse.jetty-jetty-servlet-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505) ~[org.eclipse.jetty-jetty-servlet-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:234) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:181) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) ~[org.eclipse.jetty-jetty-server-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[org.eclipse.jetty-jetty-io-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[org.eclipse.jetty-jetty-io-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) ~[org.eclipse.jetty-jetty-io-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) ~[org.eclipse.jetty-jetty-util-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) ~[org.eclipse.jetty-jetty-util-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) ~[org.eclipse.jetty-jetty-util-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) ~[org.eclipse.jetty-jetty-util-9.4.51.v20230217.jar:9.4.51.v20230217],
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) ~[org.eclipse.jetty-jetty-util-9.4.51.v20230217.jar:9.4.51.v20230217],
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?],
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?],
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[io.netty-netty-common-4.1.93.Final.jar:4.1.93.Final],
    at java.lang.Thread.run(Thread.java:840) ~[?:?],
2024-01-22T10:41:35,043+0000 [function-web-61-4] INFO  org.eclipse.jetty.server.RequestLog - 10.0.4.84 - - [22/Jan/2024:10:41:35 +0000] "PUT /admin/v3/functions/public/ticdc/test-fn HTTP/1.1" 400 151 "-" "Pulsar-Java-v2.11.3" 8

jiangpengcheng commented 8 months ago

I see, the error happens when using thread/process runtime, and the functionsWorkerEnablePackageManagement config is set to false(default is false)

I will submit a PR to fix it, in the meantime, you can set the functionsWorkerEnablePackageManagement = true in your conf/functions_worker.yml to avoid such error @truong-hua

jiangpengcheng commented 8 months ago

this error also exists in the master, 3.1 and 3.0 branches too, cc @Technoboy-

truong-hua commented 8 months ago

@jiangpengcheng the document does not mention about functionsWorkerEnablePackageManagement to enable package management. Our cluster currently has only enablePackagesManagement=true in broker config and I think our functions is using managed packages.

Btw, I checked and seem like I'm having a lot of unmanaged packages uploaded due to function updating (I checked zk /pulsar/functions/...). Is there are any proper way for me to delete them?

jiangpengcheng commented 8 months ago

the doc misses this config, you can also add this functionsWorkerEnablePackageManagement to the broker config file, the functionWorker will adopt it

for the unmanaged packages, I also don't have any good idea to delete them, you may need to delete them manually or write a program to do that, after set functionsWorkerEnablePackageManagement to true, it won't upload temp package files to the bookkeeper

BTW, are you using thread/process runtime in your production env? you can try with the k8s runtime or https://github.com/streamnative/function-mesh which is much more powerful than thread/process

apache / pulsar