microsoft / botbuilder-java

The Microsoft Bot Framework provides what you need to build and connect intelligent bots that interact naturally wherever your users are talking, from text/sms to Skype, Slack, Office 365 mail and other popular services.
http://botframework.com
MIT License
178 stars 115 forks source link

Error in Sending Adaptive Card with People Picker to Message #1476

Open johnmiroki opened 2 years ago

johnmiroki commented 2 years ago

Github issues should be used for bugs and feature requests. Use Stack Overflow for general "how-to" questions.

Version

What package version of the SDK are you using. 4.14.2

Describe the bug

Give a clear and concise description of what the bug is. When sending message using adaptive card that contains a People Picker with dataset, Activity can't be serialized (FlatterningSerializer throws error):

Caused by: java.lang.ClassCastException: class com.fasterxml.jackson.databind.node.ArrayNode cannot be cast to class com.fasterxml.jackson.databind.node.ObjectNode (com.fasterxml.jackson.databind.node.ArrayNode and com.fasterxml.jackson.databind.node.ObjectNode are in unnamed module of loader 'app') at com.microsoft.bot.restclient.serializer.FlatteningSerializer.serialize(FlatteningSerializer.java:187) ~[bot-connector-4.14.2.jar:4.14.2] at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider._serialize(DefaultSerializerProvider.java:480) ~[jackson-databind-2.13.3.jar:2.13.3] ... 27 common frames omitted

To Reproduce

Steps to reproduce the behavior: 1 Prepare an adaptive card containing People Picker:

    {
      "type": "Input.ChoiceSet",
      "choices": [],
      "choices.data": {
        "type": "Data.Query",
        "dataset": "graph.microsoft.com/users?scope=currentContext"
      },
      "isMultiSelect": true,
      "placeholder": "Choose at least one person for this feedback",
      "label": "Request to",
      "style": "filtered",
      "id": "userId"
    },
  1. Send card as message
  2. See error in log

Expected behavior

Give a clear and concise description of what you expected to happen. Expect adaptive card to be sent to chat

Screenshots

If applicable, add screenshots to help explain your problem.

Additional context

Add any other context about the problem here. The same adaptive card works for Task Module. The problem is in FlatterningSerializer, where it tries to flat "choices.data", how ever, this can't be done, for the expected flatterned data is:

choices: {
  data: {..}
}

but there's already a choices: [] existing. These two can't match.

tdurnford commented 2 years ago

@johnmiroki What channel are you using?

johnmiroki commented 2 years ago

@tdurnford Teams channel is used.

InfinytRam commented 1 year ago

Thanks, @johnmiroki, I'm investigating this.

InfinytRam commented 1 year ago

Hi @johnmiroki,

Thanks for raising this issue, I was able to repro.

Looks like when sending People Picker in Adaptive Cards, the following error message is thrown:


[INFO ] 2022-07-12 01:06:25.521 [main] Application - Started Application in 2.103 seconds (JVM running for 2.973)
2022-07-12 01:06:35.223  INFO 9512 --- [nio-3978-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
[INFO ] 2022-07-12 01:06:35.224 [http-nio-3978-exec-1] DispatcherServlet - Initializing Servlet 'dispatcherServlet'
[DEBUG] 2022-07-12 01:06:35.224 [http-nio-3978-exec-1] DispatcherServlet - Detected StandardServletMultipartResolver
[DEBUG] 2022-07-12 01:06:35.224 [http-nio-3978-exec-1] DispatcherServlet - Detected AcceptHeaderLocaleResolver
[DEBUG] 2022-07-12 01:06:35.224 [http-nio-3978-exec-1] DispatcherServlet - Detected FixedThemeResolver
[DEBUG] 2022-07-12 01:06:35.224 [http-nio-3978-exec-1] DispatcherServlet - Detected org.springframework.web.servlet.view.DefaultRequestToViewNameTranslator@42c6299d
[DEBUG] 2022-07-12 01:06:35.224 [http-nio-3978-exec-1] DispatcherServlet - Detected org.springframework.web.servlet.support.SessionFlashMapManager@a044ab6
[DEBUG] 2022-07-12 01:06:35.225 [http-nio-3978-exec-1] DispatcherServlet - enableLoggingRequestDetails='false': request parameters and headers will be masked to prevent unsafe logging of potentially sensitive data
[INFO ] 2022-07-12 01:06:35.225 [http-nio-3978-exec-1] DispatcherServlet - Completed initialization in 1 ms
[DEBUG] 2022-07-12 01:06:35.232 [http-nio-3978-exec-1] DispatcherServlet - POST "/api/messages", parameters={}
[DEBUG] 2022-07-12 01:06:35.234 [http-nio-3978-exec-1] RequestMappingHandlerMapping - Mapped to com.microsoft.bot.integration.spring.BotController#incoming(Activity, String)
[DEBUG] 2022-07-12 01:06:35.325 [http-nio-3978-exec-1] RequestResponseBodyMethodProcessor - Read "application/json;charset=utf-8" to [com.microsoft.bot.schema.Activity@355961c2]
[DEBUG] 2022-07-12 01:06:35.360 [http-nio-3978-exec-1] WebAsyncManager - Started async request
[DEBUG] 2022-07-12 01:06:35.361 [http-nio-3978-exec-1] DispatcherServlet - Exiting but response remains open for further handling
2022-07-12 01:06:36.600  INFO 9512 --- [          Bot-9] com.microsoft.bot.connector.UserAgent    : UserAgent: BotBuilder/4.0.0 (JVM 11.0.12; Windows 10)
2022-07-12 01:06:36.711 ERROR 9512 --- [          Bot-2] c.m.b.i.AdapterWithErrorHandler          : onTurnError

java.util.concurrent.CompletionException: java.lang.RuntimeException: Unable to convert com.microsoft.bot.schema.Activity@6777aad0 to RequestBody
    at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) ~[na:na]
    at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:670) ~[na:na]
    at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658) ~[na:na]
    at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094) ~[na:na]
    at com.microsoft.bot.connector.rest.RestConversations.replyToActivity(RestConversations.java:469) ~[bot-connector-4.14.1.jar:4.14.1]
    at com.microsoft.bot.connector.Conversations.replyToActivity(Conversations.java:202) ~[bot-connector-4.14.1.jar:4.14.1]
    at com.microsoft.bot.builder.BotFrameworkAdapter.lambda$sendActivities$5(BotFrameworkAdapter.java:618) ~[bot-builder-4.14.1.jar:4.14.1]
    at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) ~[na:na]
    at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1692) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594) ~[na:na]
    at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183) ~[na:na]
Caused by: java.lang.RuntimeException: Unable to convert com.microsoft.bot.schema.Activity@6777aad0 to RequestBody
    at retrofit2.ParameterHandler$Body.apply(ParameterHandler.java:357) ~[retrofit-2.5.0.jar:na]
    at retrofit2.RequestFactory.create(RequestFactory.java:108) ~[retrofit-2.5.0.jar:na]
    at retrofit2.OkHttpCall.createRawCall(OkHttpCall.java:190) ~[retrofit-2.5.0.jar:na]
    at retrofit2.OkHttpCall.enqueue(OkHttpCall.java:100) ~[retrofit-2.5.0.jar:na]
    at retrofit2.CompletableFutureCallAdapterFactory$ResponseCallAdapter.adapt(CompletableFutureCallAdapterFactory.java:117) ~[retrofit-2.5.0.jar:na]
    at retrofit2.CompletableFutureCallAdapterFactory$ResponseCallAdapter.adapt(CompletableFutureCallAdapterFactory.java:94) ~[retrofit-2.5.0.jar:na]
    at retrofit2.HttpServiceMethod.invoke(HttpServiceMethod.java:89) ~[retrofit-2.5.0.jar:na]
    at retrofit2.Retrofit$1.invoke(Retrofit.java:147) ~[retrofit-2.5.0.jar:na]
    at com.microsoft.bot.connector.rest.$Proxy85.replyToActivity(Unknown Source) ~[na:4.14.1]
    at com.microsoft.bot.connector.rest.RestConversations.replyToActivity(RestConversations.java:460) ~[bot-connector-4.14.1.jar:4.14.1]
    ... 9 common frames omitted
Caused by: com.fasterxml.jackson.databind.JsonMappingException: class com.fasterxml.jackson.databind.node.ArrayNode cannot be cast to class com.fasterxml.jackson.databind.node.ObjectNode (com.fasterxml.jackson.databind.node.ArrayNode and com.fasterxml.jackson.databind.node.ObjectNode are in unnamed module of loader 'app')
    at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider._wrapAsIOE(DefaultSerializerProvider.java:509) ~[jackson-databind-2.11.3.jar:2.11.3]
    at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider._serialize(DefaultSerializerProvider.java:482) ~[jackson-databind-2.11.3.jar:2.11.3]
    at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider.serializeValue(DefaultSerializerProvider.java:319) ~[jackson-databind-2.11.3.jar:2.11.3]
    at com.fasterxml.jackson.databind.ObjectWriter$Prefetch.serialize(ObjectWriter.java:1516) ~[jackson-databind-2.11.3.jar:2.11.3]
    at com.fasterxml.jackson.databind.ObjectWriter._writeValueAndClose(ObjectWriter.java:1217) ~[jackson-databind-2.11.3.jar:2.11.3]
    at com.fasterxml.jackson.databind.ObjectWriter.writeValueAsBytes(ObjectWriter.java:1110) ~[jackson-databind-2.11.3.jar:2.11.3]
    at com.microsoft.bot.restclient.serializer.JacksonConverterFactory$JacksonRequestBodyConverter.convert(JacksonConverterFactory.java:75) ~[bot-connector-4.14.1.jar:4.14.1]
    at com.microsoft.bot.restclient.serializer.JacksonConverterFactory$JacksonRequestBodyConverter.convert(JacksonConverterFactory.java:66) ~[bot-connector-4.14.1.jar:4.14.1]
    at retrofit2.ParameterHandler$Body.apply(ParameterHandler.java:355) ~[retrofit-2.5.0.jar:na]
    ... 18 common frames omitted
Caused by: java.lang.ClassCastException: class com.fasterxml.jackson.databind.node.ArrayNode cannot be cast to class com.fasterxml.jackson.databind.node.ObjectNode (com.fasterxml.jackson.databind.node.ArrayNode and com.fasterxml.jackson.databind.node.ObjectNode are in unnamed module of loader 'app')
    at com.microsoft.bot.restclient.serializer.FlatteningSerializer.serialize(FlatteningSerializer.java:187) ~[bot-connector-4.14.1.jar:4.14.1]
    at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider._serialize(DefaultSerializerProvider.java:480) ~[jackson-databind-2.11.3.jar:2.11.3]
    ... 25 common frames omitted

[DEBUG] 2022-07-12 01:06:38.811 [Bot-2] WebAsyncManager - Async result set, dispatch to /api/messages
[DEBUG] 2022-07-12 01:06:38.829 [http-nio-3978-exec-2] DispatcherServlet - "ASYNC" dispatch for POST "/api/messages", parameters={}
[DEBUG] 2022-07-12 01:06:38.833 [http-nio-3978-exec-2] RequestMappingHandlerAdapter - Resume with async result [<202 ACCEPTED Accepted,[]>]
[DEBUG] 2022-07-12 01:06:38.849 [http-nio-3978-exec-2] HttpEntityMethodProcessor - No match for [*/*], supported: []
[DEBUG] 2022-07-12 01:06:38.851 [http-nio-3978-exec-2] DispatcherServlet - Exiting from "ASYNC" dispatch, status 202

Error source code: /bot-connector/src/main/java/com/microsoft/bot/restclient/serializer/FlatteningSerializer.java

johnmiroki commented 1 year ago

@ramfattah Thank you for the confirmation! May I ask what's the next action from Microsoft?

InfinytRam commented 1 year ago

Thank you @johnmiroki, we are working on this fix for the next patch release.

InfinytRam commented 1 year ago

Attached is a sample repro zip project. Combined sample 07.using-adaptive-cards & 46.teams-auth.

46.teams-auth.zip

#

Call stack to FlatterningSerializer:

serialize:155, FlatteningSerializer (com.microsoft.bot.restclient.serializer) _serialize:480, DefaultSerializerProvider (com.fasterxml.jackson.databind.ser) serializeValue:319, DefaultSerializerProvider (com.fasterxml.jackson.databind.ser) serialize:1516, ObjectWriter$Prefetch (com.fasterxml.jackson.databind) _writeValueAndClose:1217, ObjectWriter (com.fasterxml.jackson.databind) writeValueAsBytes:1110, ObjectWriter (com.fasterxml.jackson.databind) convert:75, JacksonConverterFactory$JacksonRequestBodyConverter (com.microsoft.bot.restclient.serializer) convert:66, JacksonConverterFactory$JacksonRequestBodyConverter (com.microsoft.bot.restclient.serializer) apply:355, ParameterHandler$Body (retrofit2) create:108, RequestFactory (retrofit2) createRawCall:190, OkHttpCall (retrofit2) enqueue:100, OkHttpCall (retrofit2) adapt:117, CompletableFutureCallAdapterFactory$ResponseCallAdapter (retrofit2) adapt:94, CompletableFutureCallAdapterFactory$ResponseCallAdapter (retrofit2) invoke:89, HttpServiceMethod (retrofit2) invoke:147, Retrofit$1 (retrofit2) replyToActivity:-1, $Proxy85 (com.microsoft.bot.connector.rest) replyToActivity:460, RestConversations (com.microsoft.bot.connector.rest) replyToActivity:202, Conversations (com.microsoft.bot.connector) lambda$sendActivities$5:618, BotFrameworkAdapter (com.microsoft.bot.builder) get:-1, 1272797835 (com.microsoft.bot.builder.BotFrameworkAdapter$$Lambda$723) run$$$capture:1700, CompletableFuture$AsyncSupply (java.util.concurrent) run:-1, CompletableFuture$AsyncSupply (java.util.concurrent)

  • Async stack trace :1686, CompletableFuture$AsyncSupply (java.util.concurrent) asyncSupplyStage:1714, CompletableFuture (java.util.concurrent) supplyAsync:1931, CompletableFuture (java.util.concurrent) sendActivities:579, BotFrameworkAdapter (com.microsoft.bot.builder) sendActivitiesThroughAdapter:418, TurnContextImpl (com.microsoft.bot.builder) sendActivities:385, TurnContextImpl (com.microsoft.bot.builder) sendActivity:346, TurnContextImpl (com.microsoft.bot.builder) lambda$onMembersAdded$1:51, TeamsBot (com.microsoft.bot.sample.teamsauth) accept:195, ReferencePipeline$3$1 (java.util.stream) accept:177, ReferencePipeline$2$1 (java.util.stream) forEachRemaining:1655, ArrayList$ArrayListSpliterator (java.util) copyInto:484, AbstractPipeline (java.util.stream) wrapAndCopyInto:474, AbstractPipeline (java.util.stream) evaluateSequential:913, ReduceOps$ReduceOp (java.util.stream) evaluate:234, AbstractPipeline (java.util.stream) collect:578, ReferencePipeline (java.util.stream) onMembersAdded:53, TeamsBot (com.microsoft.bot.sample.teamsauth) onConversationUpdateActivity:168, ActivityHandler (com.microsoft.bot.builder) onConversationUpdateActivity:624, TeamsActivityHandler (com.microsoft.bot.builder.teams) onTurn:81, ActivityHandler (com.microsoft.bot.builder) onTurn:44, DialogBot (com.microsoft.bot.sample.teamsauth) receiveActivityInternal:99, MiddlewareSet (com.microsoft.bot.builder) lambda$receiveActivityInternal$1:110, MiddlewareSet (com.microsoft.bot.builder) onTurn:1430, BotFrameworkAdapter$TenantIdWorkaroundForTeamsMiddleware (com.microsoft.bot.builder) receiveActivityInternal:109, MiddlewareSet (com.microsoft.bot.builder) receiveActivityInternal:74, MiddlewareSet (com.microsoft.bot.builder) receiveActivityWithStatus:67, MiddlewareSet (com.microsoft.bot.builder) runPipeline:206, BotAdapter (com.microsoft.bot.builder) lambda$processActivity$2:478, BotFrameworkAdapter (com.microsoft.bot.builder) uniComposeStage:1106, CompletableFuture (java.util.concurrent) thenCompose:2235, CompletableFuture (java.util.concurrent) processActivity:476, BotFrameworkAdapter (com.microsoft.bot.builder) lambda$processActivity$1:433, BotFrameworkAdapter (com.microsoft.bot.builder) tryFire:1072, CompletableFuture$UniCompose (java.util.concurrent) postComplete:506, CompletableFuture (java.util.concurrent) run$$$capture:1705, CompletableFuture$AsyncSupply (java.util.concurrent) run:-1, CompletableFuture$AsyncSupply (java.util.concurrent)
  • Async stack trace :1686, CompletableFuture$AsyncSupply (java.util.concurrent) asyncSupplyStage:1714, CompletableFuture (java.util.concurrent) supplyAsync:1931, CompletableFuture (java.util.concurrent) validateToken:142, JwtTokenExtractor (com.microsoft.bot.connector.authentication) getIdentity:127, JwtTokenExtractor (com.microsoft.bot.connector.authentication) getIdentity:96, JwtTokenExtractor (com.microsoft.bot.connector.authentication) getIdentity:74, JwtTokenExtractor (com.microsoft.bot.connector.authentication) authenticateToken:112, ChannelValidation (com.microsoft.bot.connector.authentication) authenticateToken:206, ChannelValidation (com.microsoft.bot.connector.authentication) authenticateToken:201, JwtTokenValidation (com.microsoft.bot.connector.authentication) validateAuthHeader:159, JwtTokenValidation (com.microsoft.bot.connector.authentication) authenticateRequest:98, JwtTokenValidation (com.microsoft.bot.connector.authentication) processActivity:432, BotFrameworkAdapter (com.microsoft.bot.builder) processIncomingActivity:102, BotFrameworkHttpAdapter (com.microsoft.bot.integration) incoming:84, BotController (com.microsoft.bot.integration.spring) invoke0:-2, NativeMethodAccessorImpl (jdk.internal.reflect) invoke:62, NativeMethodAccessorImpl (jdk.internal.reflect) invoke:43, DelegatingMethodAccessorImpl (jdk.internal.reflect) invoke:566, Method (java.lang.reflect) doInvoke:197, InvocableHandlerMethod (org.springframework.web.method.support) invokeForRequest:141, InvocableHandlerMethod (org.springframework.web.method.support) invokeAndHandle:106, ServletInvocableHandlerMethod (org.springframework.web.servlet.mvc.method.annotation) invokeHandlerMethod:893, RequestMappingHandlerAdapter (org.springframework.web.servlet.mvc.method.annotation) handleInternal:807, RequestMappingHandlerAdapter (org.springframework.web.servlet.mvc.method.annotation) handle:87, AbstractHandlerMethodAdapter (org.springframework.web.servlet.mvc.method) doDispatch:1061, DispatcherServlet (org.springframework.web.servlet) doService:961, DispatcherServlet (org.springframework.web.servlet) processRequest:1006, FrameworkServlet (org.springframework.web.servlet) doPost:909, FrameworkServlet (org.springframework.web.servlet) service:652, HttpServlet (javax.servlet.http) service:883, FrameworkServlet (org.springframework.web.servlet) service:733, HttpServlet (javax.servlet.http) internalDoFilter:231, ApplicationFilterChain (org.apache.catalina.core) doFilter:166, ApplicationFilterChain (org.apache.catalina.core) doFilter:53, WsFilter (org.apache.tomcat.websocket.server) internalDoFilter:193, ApplicationFilterChain (org.apache.catalina.core) doFilter:166, ApplicationFilterChain (org.apache.catalina.core) doFilterInternal:100, RequestContextFilter (org.springframework.web.filter) doFilter:119, OncePerRequestFilter (org.springframework.web.filter) internalDoFilter:193, ApplicationFilterChain (org.apache.catalina.core) doFilter:166, ApplicationFilterChain (org.apache.catalina.core) doFilterInternal:93, FormContentFilter (org.springframework.web.filter) doFilter:119, OncePerRequestFilter (org.springframework.web.filter) internalDoFilter:193, ApplicationFilterChain (org.apache.catalina.core) doFilter:166, ApplicationFilterChain (org.apache.catalina.core) doFilterInternal:201, CharacterEncodingFilter (org.springframework.web.filter) doFilter:119, OncePerRequestFilter (org.springframework.web.filter) internalDoFilter:193, ApplicationFilterChain (org.apache.catalina.core) doFilter:166, ApplicationFilterChain (org.apache.catalina.core) invoke:202, StandardWrapperValve (org.apache.catalina.core) invoke:97, StandardContextValve (org.apache.catalina.core) invoke:542, AuthenticatorBase (org.apache.catalina.authenticator) invoke:143, StandardHostValve (org.apache.catalina.core) invoke:92, ErrorReportValve (org.apache.catalina.valves) invoke:78, StandardEngineValve (org.apache.catalina.core) service:343, CoyoteAdapter (org.apache.catalina.connector) service:374, Http11Processor (org.apache.coyote.http11) process:65, AbstractProcessorLight (org.apache.coyote) process:868, AbstractProtocol$ConnectionHandler (org.apache.coyote) doRun:1590, NioEndpoint$SocketProcessor (org.apache.tomcat.util.net) run:49, SocketProcessorBase (org.apache.tomcat.util.net) runWorker:1128, ThreadPoolExecutor (java.util.concurrent) run:628, ThreadPoolExecutor$Worker (java.util.concurrent) run:61, TaskThread$WrappingRunnable (org.apache.tomcat.util.threads) run:829, Thread (java.lang)
johnmiroki commented 1 year ago

@ramfattah Thanks a lot!

tracyboehrer commented 1 year ago

@johnmiroki This is next on my list. Ram and I will resolve it and include in the next patch release for Java. I don't have a solid ETA on that release, but it's sooner rather than later.

johnmiroki commented 1 year ago

@tracyboehrer good to hear. Thank you very much!

johnmiroki commented 1 year ago

@tracyboehrer Hi Tracy, any ETA regarding this fix? Much appreciated!

tracyboehrer commented 1 year ago

The root of the problem is the 'choices.data' property. It would appear this is a flattened JSON property. I do believe that this should be an object under the 'choices' array. It's a tricky issue and it will take me more research to understand this JSON notation. What the existing FlatteningSerialzier is doing just doesn't handle it correctly.

In other words, I think a mitigating step is to change the JSON.

johnmiroki commented 1 year ago

@tracyboehrer agreed. It's rare to use a property as an object and an array at the same time. But the change should be from MS side. We as third party developers can't do much about it.