RequestLoggingFilter manipulates inputstream - Streaming not achievable
githubsree opened this issue · 6 comments
Hi colleagues,
We are from "C21- Sustainability services". We are building application in SCP CF. Previously, we noticed that the usage of library - cf-java-logging-support-servlet, breaks the streaming ability of the application.
When dug through the underlying code in RequestLoggingFilter.java , could notice this piece,
if (wrapResponse) {
responseWrapper = new ContentLengthTrackingResponseWrapper(httpResponse);
}
if (wrapRequest) {
requestWrapper = new ContentLengthTrackingRequestWrapper(httpRequest);
}
This is consuming the "InputStream" and "OutputStream" which breaks the streaming ability.
Please check here : https://stackoverflow.com/questions/39748536/spring-upload-non-multipart-file-as-a-stream
Can you propose a solution for this?
The kind of applications we deal with are
-> CAP based : OData & REST
-> Spring-Boot based : REST
Thank You
Regards
Sreeram
We will have to look into this one. Can you give more information on the problem, maybe a small demo of the problem? The wrapper classes actually only wrap the request and response streams but do not actively consume them. There is one more wrapper: LoggingContextRequestWrapper reacts on asynchronous requests but does not touch the streams.
Hi @KarstenSchnitter ,
I just wrote a very basic streaming controller as below:
@Controller
public class TestController {
@RequestMapping("/test2")
public ResponseEntity<StreamingResponseBody> handleRequest () {
StreamingResponseBody responseBody = new StreamingResponseBody() {
@Override
public void writeTo (OutputStream out) throws IOException {
for (int i = 0; i < 1000; i++) {
out.write((Integer.toString(i) + " - ")
.getBytes());
out.flush();
try {
Thread.sleep(5);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
};
return new ResponseEntity(responseBody, HttpStatus.OK);
}
}
Streaming didn't work, then I by passed the RequestLoggingFilter like below (Overrode it)
@Bean(name = "SAPCFRequestLoggingFilter")
public Filter sapLoggingFilter() {
RequestLoggingFilter loggingFilter = new RequestLoggingFilter() {
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
throws IOException, ServletException {
chain.doFilter(request, response);
}
};
return loggingFilter;
}
Basically, just did chain.doFilter(request, response); to skip the logic inside RequestLoggingFilter.
Then the streaming started working.
Please have a look at branch issue/91. I added your code as a controller to the Spring Boot sample app:
When I start the app, the endpoint works:
$ curl --user user:secret localhost:8080/stream
0 - 1 - 2 - 3 - 4 - 5 - 6 - 7 - 8 - 9 - 10 - 11 - 12 - 13 - 14 - 15 - 16 - 17 - 18 - 19 - 20 - 21 - 22 - 23 - 24 - 25 - 26 - 27 - 28 - 29 - 30 - 31 - 32 - 33 - 34 - 35 - 36 - 37 - 38 - 39 - 40 - 41 - 42 - 43 - 44 - 45 - 46 - 47 - 48 - 49 - 50 - 51 - 52 - 53 - 54 - 55 - 56 - 57 - 58 - 59 - 60 - 61 - 62 - 63 - 64 - 65 - 66 - 67 - 68 - 69 - 70 - 71 - 72 - 73 - 74 - 75 - 76 - 77 - 78 - 79 - 80 - 81 - 82 - 83 - 84 - 85 - 86 - 87 - 88 - 89 - 90 - 91 - 92 - 93 - 94 - 95 - 96 - 97 - 98 - 99 - 100 - 101 - 102 - 103 - 104 - 105 - 106 - 107 - 108 - 109 - 110 - 111 - 112 - 113 - 114 - 115 - 116 - 117 - 118 - 119 - 120 - 121 - 122 - 123 - 124 - 125 - 126 - 127 - 128 - 129 - 130 - 131 - 132 - 133 - 134 - 135 - 136 - 137 - 138 - 139 - 140 - 141 - 142 - 143 - 144 - 145 - 146 - 147 - 148 - 149 - 150 - 151 - 152 - 153 - 154 - 155 - 156 - 157 - 158 - 159 - 160 - 161 - 162 - 163 - 164 - 165 - 166 - 167 - 168 - 169 - 170 - 171 - 172 - 173 - 174 - 175 - 176 - 177 - 178 - 179 - 180 - 181 - 182 - 183 - 184 - 185 - 186 - 187 - 188 - 189 - 190 - 191 - 192 - 193 - 194 - 195 - 196 - 197 - 198 - 199 - 200 - 201 - 202 - 203 - 204 - 205 - 206 - 207 - 208 - 209 - 210 - 211 - 212 - 213 - 214 - 215 - 216 - 217 - 218 - 219 - 220 - 221 - 222 - 223 - 224 - 225 - 226 - 227 - 228 - 229 - 230 - 231 - 232 - 233 - 234 - 235 - 236 - 237 - 238 - 239 - 240 - 241 - 242 - 243 - 244 - 245 - 246 - 247 - 248 - 249 - 250 - 251 - 252 - 253 - 254 - 255 - 256 - 257 - 258 - 259 - 260 - 261 - 262 - 263 - 264 - 265 - 266 - 267 - 268 - 269 - 270 - 271 - 272 - 273 - 274 - 275 - 276 - 277 - 278 - 279 - 280 - 281 - 282 - 283 - 284 - 285 - 286 - 287 - 288 - 289 - 290 - 291 - 292 - 293 - 294 - 295 - 296 - 297 - 298 - 299 - 300 - 301 - 302 - 303 - 304 - 305 - 306 - 307 - 308 - 309 - 310 - 311 - 312 - 313 - 314 - 315 - 316 - 317 - 318 - 319 - 320 - 321 - 322 - 323 - 324 - 325 - 326 - 327 - 328 - 329 - 330 - 331 - 332 - 333 - 334 - 335 - 336 - 337 - 338 - 339 - 340 - 341 - 342 - 343 - 344 - 345 - 346 - 347 - 348 - 349 - 350 - 351 - 352 - 353 - 354 - 355 - 356 - 357 - 358 - 359 - 360 - 361 - 362 - 363 - 364 - 365 - 366 - 367 - 368 - 369 - 370 - 371 - 372 - 373 - 374 - 375 - 376 - 377 - 378 - 379 - 380 - 381 - 382 - 383 - 384 - 385 - 386 - 387 - 388 - 389 - 390 - 391 - 392 - 393 - 394 - 395 - 396 - 397 - 398 - 399 - 400 - 401 - 402 - 403 - 404 - 405 - 406 - 407 - 408 - 409 - 410 - 411 - 412 - 413 - 414 - 415 - 416 - 417 - 418 - 419 - 420 - 421 - 422 - 423 - 424 - 425 - 426 - 427 - 428 - 429 - 430 - 431 - 432 - 433 - 434 - 435 - 436 - 437 - 438 - 439 - 440 - 441 - 442 - 443 - 444 - 445 - 446 - 447 - 448 - 449 - 450 - 451 - 452 - 453 - 454 - 455 - 456 - 457 - 458 - 459 - 460 - 461 - 462 - 463 - 464 - 465 - 466 - 467 - 468 - 469 - 470 - 471 - 472 - 473 - 474 - 475 - 476 - 477 - 478 - 479 - 480 - 481 - 482 - 483 - 484 - 485 - 486 - 487 - 488 - 489 - 490 - 491 - 492 - 493 - 494 - 495 - 496 - 497 - 498 - 499 - 500 - 501 - 502 - 503 - 504 - 505 - 506 - 507 - 508 - 509 - 510 - 511 - 512 - 513 - 514 - 515 - 516 - 517 - 518 - 519 - 520 - 521 - 522 - 523 - 524 - 525 - 526 - 527 - 528 - 529 - 530 - 531 - 532 - 533 - 534 - 535 - 536 - 537 - 538 - 539 - 540 - 541 - 542 - 543 - 544 - 545 - 546 - 547 - 548 - 549 - 550 - 551 - 552 - 553 - 554 - 555 - 556 - 557 - 558 - 559 - 560 - 561 - 562 - 563 - 564 - 565 - 566 - 567 - 568 - 569 - 570 - 571 - 572 - 573 - 574 - 575 - 576 - 577 - 578 - 579 - 580 - 581 - 582 - 583 - 584 - 585 - 586 - 587 - 588 - 589 - 590 - 591 - 592 - 593 - 594 - 595 - 596 - 597 - 598 - 599 - 600 - 601 - 602 - 603 - 604 - 605 - 606 - 607 - 608 - 609 - 610 - 611 - 612 - 613 - 614 - 615 - 616 - 617 - 618 - 619 - 620 - 621 - 622 - 623 - 624 - 625 - 626 - 627 - 628 - 629 - 630 - 631 - 632 - 633 - 634 - 635 - 636 - 637 - 638 - 639 - 640 - 641 - 642 - 643 - 644 - 645 - 646 - 647 - 648 - 649 - 650 - 651 - 652 - 653 - 654 - 655 - 656 - 657 - 658 - 659 - 660 - 661 - 662 - 663 - 664 - 665 - 666 - 667 - 668 - 669 - 670 - 671 - 672 - 673 - 674 - 675 - 676 - 677 - 678 - 679 - 680 - 681 - 682 - 683 - 684 - 685 - 686 - 687 - 688 - 689 - 690 - 691 - 692 - 693 - 694 - 695 - 696 - 697 - 698 - 699 - 700 - 701 - 702 - 703 - 704 - 705 - 706 - 707 - 708 - 709 - 710 - 711 - 712 - 713 - 714 - 715 - 716 - 717 - 718 - 719 - 720 - 721 - 722 - 723 - 724 - 725 - 726 - 727 - 728 - 729 - 730 - 731 - 732 - 733 - 734 - 735 - 736 - 737 - 738 - 739 - 740 - 741 - 742 - 743 - 744 - 745 - 746 - 747 - 748 - 749 - 750 - 751 - 752 - 753 - 754 - 755 - 756 - 757 - 758 - 759 - 760 - 761 - 762 - 763 - 764 - 765 - 766 - 767 - 768 - 769 - 770 - 771 - 772 - 773 - 774 - 775 - 776 - 777 - 778 - 779 - 780 - 781 - 782 - 783 - 784 - 785 - 786 - 787 - 788 - 789 - 790 - 791 - 792 - 793 - 794 - 795 - 796 - 797 - 798 - 799 - 800 - 801 - 802 - 803 - 804 - 805 - 806 - 807 - 808 - 809 - 810 - 811 - 812 - 813 - 814 - 815 - 816 - 817 - 818 - 819 - 820 - 821 - 822 - 823 - 824 - 825 - 826 - 827 - 828 - 829 - 830 - 831 - 832 - 833 - 834 - 835 - 836 - 837 - 838 - 839 - 840 - 841 - 842 - 843 - 844 - 845 - 846 - 847 - 848 - 849 - 850 - 851 - 852 - 853 - 854 - 855 - 856 - 857 - 858 - 859 - 860 - 861 - 862 - 863 - 864 - 865 - 866 - 867 - 868 - 869 - 870 - 871 - 872 - 873 - 874 - 875 - 876 - 877 - 878 - 879 - 880 - 881 - 882 - 883 - 884 - 885 - 886 - 887 - 888 - 889 - 890 - 891 - 892 - 893 - 894 - 895 - 896 - 897 - 898 - 899 - 900 - 901 - 902 - 903 - 904 - 905 - 906 - 907 - 908 - 909 - 910 - 911 - 912 - 913 - 914 - 915 - 916 - 917 - 918 - 919 - 920 - 921 - 922 - 923 - 924 - 925 - 926 - 927 - 928 - 929 - 930 - 931 - 932 - 933 - 934 - 935 - 936 - 937 - 938 - 939 - 940 - 941 - 942 - 943 - 944 - 945 - 946 - 947 - 948 - 949 - 950 - 951 - 952 - 953 - 954 - 955 - 956 - 957 - 958 - 959 - 960 - 961 - 962 - 963 - 964 - 965 - 966 - 967 - 968 - 969 - 970 - 971 - 972 - 973 - 974 - 975 - 976 - 977 - 978 - 979 - 980 - 981 - 982 - 983 - 984 - 985 - 986 - 987 - 988 - 989 - 990 - 991 - 992 - 993 - 994 - 995 - 996 - 997 - 998 - 999 -
It produces the following log messages:
{ "written_at":"2021-01-20T09:03:43.253Z","written_ts":1611133423253876000,"tenant_id":"-","component_id":"-","component_name":"-","organization_name":"-","component_type":"application","space_name":"-","component_instance":"0","organization_id":"-","correlation_id":"1ed16f54-677e-42c1-9ad4-4eb8cf6bf653","space_id":"-","container_id":"-","tenant_subdomain":"-","type":"log","logger":"org.springframework.web.context.request.async.WebAsyncManager","thread":"http-nio-8080-exec-1","level":"WARN","categories":[],"msg":"\n!!!\nAn Executor is required to handle java.util.concurrent.Callable return values.\nPlease, configure a TaskExecutor in the MVC config under \"async support\".\nThe SimpleAsyncTaskExecutor currently in use is not suitable under load.\n-------------------------------\nRequest URI: '/stream'\n!!!" }
{ "written_at":"2021-01-20T09:03:48.922Z","written_ts":1611133428925595000,"tenant_id":"-","component_id":"-","component_name":"-","organization_name":"-","component_type":"application","space_name":"-","component_instance":"0","organization_id":"-","correlation_id":"1ed16f54-677e-42c1-9ad4-4eb8cf6bf653","space_id":"-","container_id":"-","tenant_subdomain":"-","type":"request","request":"/stream","referer":"-","response_sent_at":"2021-01-20T09:03:48.922Z","response_status":200,"method":"GET","response_size_b":5890,"request_size_b":-1,"remote_port":"redacted","layer":"[SERVLET]","remote_host":"redacted","x_forwarded_for":"-","remote_user":"redacted","protocol":"HTTP/1.1","remote_ip":"redacted","response_content_type":"-","request_received_at":"2021-01-20T09:03:43.226Z","response_time_ms":5695.998096,"direction":"IN"}As you can see, the second log message is the request log created by the RequestLoggingFilter.
Do we need to change the code, to expose your problem? Or is this just working with the current version?
Hi @KarstenSchnitter ,
I was using the version : 2.1.5.
Were you able to see stream of data as output or one single chunk of output?
I am able to achieve stream only after skipping the logging filter.
Hi @githubsree,
I was able to see streamed data as output. Please update to a newer version. Current release is 3.3.0. There were quite some improvements in between the two releases. Handling asynchronous requests and improvements on request and response wrapping were some of those.