botbuilder-java icon indicating copy to clipboard operation
botbuilder-java copied to clipboard

Error in Sending Adaptive Card with People Picker to Message

Open johnmiroki opened this issue 2 years ago • 13 comments

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.

johnmiroki avatar Jun 29 '22 08:06 johnmiroki

@johnmiroki What channel are you using?

tdurnford avatar Jun 29 '22 18:06 tdurnford

@tdurnford Teams channel is used.

johnmiroki avatar Jun 30 '22 08:06 johnmiroki

Thanks, @johnmiroki, I'm investigating this.

ramfattah avatar Jun 30 '22 15:06 ramfattah

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

ramfattah avatar Jul 07 '22 05:07 ramfattah

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

johnmiroki avatar Jul 07 '22 08:07 johnmiroki

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

ramfattah avatar Jul 18 '22 23:07 ramfattah

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)

ramfattah avatar Jul 21 '22 07:07 ramfattah

@ramfattah Thanks a lot!

johnmiroki avatar Jul 21 '22 10:07 johnmiroki

@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.

tracyboehrer avatar Jul 21 '22 19:07 tracyboehrer

@tracyboehrer good to hear. Thank you very much!

johnmiroki avatar Jul 23 '22 12:07 johnmiroki

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

johnmiroki avatar Nov 05 '22 17:11 johnmiroki

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.

tracyboehrer avatar Nov 07 '22 14:11 tracyboehrer

@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.

johnmiroki avatar Jan 13 '23 05:01 johnmiroki