Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

debug logs: binary data in logs when using compression on metrics endpoint #4442

Closed
srenatus opened this issue Mar 17, 2022 · 6 comments
Closed

Comments

@srenatus
Copy link
Contributor

Short description

With debug logging enabled, compressed requests cause binary data to be logged, messing up the terminal, and being generally of little use.

Steps To Reproduce

  1. run OPA: opa run -s --log-level debug --log-format text
  2. in another terminal, run curl --compressed http://localhost:8181/metrics

With log format text, we'll get a bunch of binary soup.

When using log format JSON, we'll get something like this
{"client_addr":"[::1]:52388","level":"info","msg":"Sent response.","req_id":1,"req_method":"GET","req_path":"/metrics","resp_body":"\u001f\ufffd\u0008\u0000\u0000\u0000\u0000\u0000\u0000\ufffd\ufffd[K\ufffd\ufffd6\u0012\ufffdϯ \ufffdC\u000e\ufffdn\ufffd\ufffdX \ufffd\ufffd\u001b8\u0001v\ufffd\u0000\ufffd\u001e\ufffd\ufffd`K\ufffd\ufffd\\K\ufffd\ufffd\ufffdf\ufffd\t\ufffd\ufffd\u0017$%\ufffd\u001e\ufffdZj\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd_=XU,q\ufffdA?\ufffd\ufffd\ufffd_Й\u001e\ufffd\ufffd!\ufffdf\u0005\ufffd\u0003n\u0004-\ufffd \ufffd\ufffd\ufffd\ufffd\u0002\u0017\ufffd=m*\ufffd\ufffd\te\ufffd\ufffd\u000b\u0010\ufffd\ufffd\u000f\ufffd\ufffd\u0026Ag\ufffd\ufffda\ufffd\ufffdxE\ufffd\u0002\ufffd\u0003E\ufffd\ufffd\u0004)a\ufffd\ufffd\r\ufffd\ufffd\ufffd_~X\ufffdN\u0026\ufffd\u0001\ufffd\ufffd\ufffd\ufffd2\ufffdq\ufffd,\ufffd|\ufffd\u000e\ufffd\ufffdS\u0000\ufffduA2,\u0008\ufffd\ufffd\u001aX\ufffd0·\ufffd:F\ufffd\ufffd\ufffd\u001d:.\n\u0013|3H\ufffd,#F3\ufffdļyÔI\u000e\u001c2Z\ufffd\u001c}\ufffdxS\ufffd\ufffd]%4i\ufffd\u001a7\u001cPG'\ufffd\ufffd1;\ufffd3\ufffd\ufffd\u0016\u0005d\ufffd\ufffd\u0011\ufffdLv+\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd6\ufffd\u0012\ufffd\ufffd\ufffd\ufffd8o\ufffd@\ufffd\u003e\ufffdb\u001fvN\ufffd\ufffd~Y$G\ufffdO\ufffd0\\\ufffd\u0011K\u0016g\ufffd8\ufffd\ufffd\u0026A\u001a\ufffd\ufffdqW1\u001cxSj2\ufffdI\u001c/\ufffd\ufffd)7O=x\u0001\\\u001fpQЌ\u001f\ufffd\ufffd\u0003'\ufffd\ufffd\ufffdx\u0015\ufffd\ufffd\ufffdN\ufffd`\ufffd\ufffdtޓ\ufffdH\ufffd+\ufffd\\\ufffd\u000f\\׌\ufffdJJ,\u0000I\u0001{\ufffd\ufffd\n@\ufffd\ufffd\u0005\u0012\u0017\ufffdQN\ufffd\ufffd\ufffd\nD\ufffd\ufffdhr@\ufffdTWD\ufffd\ufffd\ufffdLp\ufffd9\ufffd\ufffdD*\ufffd\ufffdޝ\ufffdwr\ufffdw\ufffd\ufffd\ufffdF\ufffd\ufffd\ufffd\ufffd\u0019Ѫ\ufffdj\ufffdcA\ufffd/Ә\ufffd\ufffdͅpA\ufffd\u000c\ufffdO\ufffd\ufffd\u000f\ufffd\u0026\ufffd\u0002\ufffdw\ufffd\ufffdd\ufffd\ufffd\ufffd%\ufffd\ufffd\ufffd\u001bo\ufffd\ufffd\u0005\u0013Q\ufffd\u000c\u003e'\r\ufffd\ufffd\ufffd\ufffd\ufffd,\ufffd*\u000c\ufffdp\ufffd(7\ufffdȊ\ufffd\ufffd\ufffd\ufffd8r\ufffd\ufffd\ufffd|\ufffd\u0019\ufffd\n\ufffd\ufffd\ufffd\"7\u0008\u001f\ufffd\u0015;\u0013\\R\ufffd\u0017\ufffd\ufffd\u0003*\ufffd~\ufffd\ufffd:1\ufffdC/zHű\ufffd\ufffd\ufffd\u0015{\ufffd\u0003^\u000c\ufffdqx)Q\ufffd\ufffd\ufffd\u0017\ufffd0\u001a\ufffd\ufffd*\u0026\ufffd\u0003\ufffd\ufffd\ufffd\u001b\ufffdW\ufffde%\u000f\ufffd\ufffd\ufffdO\ufffdIq\ufffd\ufffd\ufffd\ufffd[\ufffd\ufffdt\u001f\ufffdQ\u001c\ufffd\u0011\ufffdu\ufffdn5\ufffd\ufffd\ufffdJ\u000b\ufffd\ufffd\ufffd\u0015\ufffd7eS`A^@\ufffd\u0018\ufffd\ufffdJ()\ufffdvy\u000er$\ufffd\ufffdf*\ufffd\ufffd\ufffd\u0008l\ufffd\ufffd묍j\ufffd\ufffdU\ufffd6%\ufffdUȺ\ufffd`\ufffd\ufffd\u0005#\ufffd30sS\ufffd\ufffd\ufffd\ufffdc\ufffd\ufffd\ufffd\u001a\ufffd\ufffd\\}b\u0000몚\ufffd\ufffd\ufffd\u001fj\ufffd]%ci\ufffd\ufffd߫l\ufffd\ufffdn\ufffdc\ufffdk\ufffd\u001b\u0007\ufffd%\ufffd\ufffdZ\u0014\u0004\ufffd!\u0019k\ufffd\ufffdž\ufffdY\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\u0026\ufffdE\ufffd*\ufffd\ufffd{q\ufffd]?SAs}?\ufffd\u001f\ufffdo^\ufffd\\?p\ufffd[\ufffdT\ufffd\\?\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\u0014\ufffdn\ufffdNS1s\ufffd\ufffd\ufffd\ufffdlk\ufffd\ufffd\u0007I\ufffd\ufffdY\ufffd\u0015o\ufffd%Q\u0014\ufffd[g\ufffd\ufffdu\"׫ؓ\ufffdR\u0019S\t\ufffd\ufffde:ŵ\ufffdr\u0006\ufffdl)\ufffd,\u0016\ufffd9\ufffdPO\u001b\ufffd\u0007\ufffd\ufffd\ufffd\ufffdr@\\P\u0026\ufffd\ufffdb~O\ufffd\ufffdB\ufffd\ufffd[\ufffdLd6\ufffd\ufffd\ufffd\u000cCii\ufffd\ufffd\ufffd\ufffd\u000c\u0018$0;\ufffd@'ʔ\u0019\ufffdʻ\ufffdw7\n0\ufffd\u001b\ufffd:\ufffd\ufffd\u000cO\ufffdw\ufffd\u003e\ufffd\ufffd0\ufffdC\u000f\ufffd:\ufffd\u0001R\u0007\ufffd\ufffd\ufffdǦ\u003c\u0002\ufffd\u0008zc\u0015ҭ\ufffd\ufffd\ufffd\ufffd\ufffdP\ufffdgD\ufffd\ufffd\ufffd\ufffd\ufffd:\u000f\ufffd\ufffd\u0004r*|\ufffdtJ\u0010:\ufffd\u0017\u0018PJWYڦ.\ufffdx\ufffd\ufffdb\ufffd,\ufffd\ufffd\ufffd\u000cP\ufffd\ufffd/\ufffd\u0003\u003c\ufffd\ufffd\u0000C\ufffd\u0012\ufffds\u003c\ufffd|\u0001\u000e#\u003eɢ\u001d\ufffd#\u000e5fX@!\ufffd\u001f-\u0011U\u0002F\u001d\u0006dj@\u00028\ufffd R\ufffd\ufffd\ufffd\ufffd\r\u001e\"ADG\ufffd`\u001aG\u001b\ufffd\ufffd4\ufffd\u000b\ufffd\u000b\u0010\ufffdA\ufffd\ufffd\u000fR\ufffd\ufffdY\ufffd\ufffd\ufffd\u0001ί\u0008g\u001d*\u0019+\ufffd\ufffdK\ufffd\ufffd\ufffd\ufffdS\ufffd\ufffd\ufffd\\\ufffd\ufffd\ufffd\ufffd\ufffd%vK\u001ab\ufffdN\ufffd{\ufffdܠ\ufffdD\ufffd\u001fU\u0018\ufffd\ufffd\ufffdq\u003e\ufffd\ufffd1(T_\ufffd\u0005\ufffdw\ufffd\u0002\ufffdWʊ\ufffd\ufffd6\ufffdWUFf\u0013%\ufffd\"Ӿ\ufffdD4L\ufffd\ufffd\u0010v\ufffd'\ufffd\ufffd\ufffd\ufffd#\ufffd43)\ufffd\\\ufffd\ufffd\ufffd\ufffdt\u0003\ufffd\ufffd\ufffd\ufffd\u0011\u0002;'\ufffdZ\u0001\ufffd\u0026\u0001\ufffd\ufffd\ufffd\u0013\u0001\ufffd\ufffd\ufffdV\nP\ufffd-w*Dv\ufffd\u001b\u0004xN\u001a\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd݋\ufffd\ufffd\u000f\ufffd0\u001ct\u001fk\ufffd\ufffd\ufffd\ufffd\u0012\ufffd\ufffd\ufffd\u001f\ufffd\ufffd%\ufffd\ufffd\\\u003c\ufffdx\ufffd\ufffdF\ufffd\n\ufffd\ufffd{\ufffdP\ufffd\ufffd\ufffda\u000c*Q\\\u0011\ufffdJ\ufffd\u0018\ufffd\ufffd\u001b\ufffd-9ߞy\ufffd*F\ufffd\u0013E?U'\ufffdJ\ufffd\ufffd\ufffd\ufffd6\ufffd\ufffd8\u0000\ufffd\u000ba\ufffd*\ufffd\u001a-\ufffd\ufffdz\ufffd\ufffd\ufffd\ufffd_\ufffdqB\ufffd\ufffdޜ\ufffd\ufffdw\ufffd\ufffd\ufffd\ufffd\u0007\ufffd\ufffdzr\ufffd\n̥\t\ufffd*ۖ\ufffd\ufffdnHiFx?9/t\ufffd\ufffd\ufffd \u0014\ufffdL\ufffd\u0005\ufffdC\ufffd\u0011\u0010\u0003Ѱ\ufffd6\u0003h\ufffd\u001cX\ufffd\n\u0018\ufffdr\u0001\ufffd3:6\u0002]\ufffd\ufffd\ufffdG\ufffdJ\ufffd\u0005\ufffdQ\t\ufffd\ufffdL.3\ufffd\ufffd\ufffdr\u0004\\\ufffd\u0003e{\ufffdD8\ufffd\u0019p\ufffdx\ufffd3\ufffd\ufffd\u001d\ufffd\ufffd__\ufffd\ufffdd\ufffd0\u0014\ufffd;\ufffd\ufffd\ufffd\ufffdC\u0017ǎ\u0013$w\ufffd\ufffd%\ufffd\ufffd%U9'\u001a\ufffd\ufffd\ufffd]GU\ufffd(\u0007\ufffd\ufffd\u000f\ufffd^\u0017\ufffd\u0002\ufffdNWжB%fRMe\ufffd5\ufffd\ufffd}d\ufffdJ\ufffdI\ufffd}\u0010%N\ufffdN\ufffd-\u0026N\u0006\u0005`\u000e\ufffd\ufffdH\ufffd1\ufffdt\ufffd\u001bCN\ufffdpA\ufffd\u0002\ufffd\ufffd\ufffd!\ufffd}\ufffd\ufffd\u0004\ufffdh\u0006\ufffd\ufffd0m\ufffd\ufffd\ufffdckb\ufffdESOh\ufffd}\ufffd\u0006a\ufffdMN\u0006\u0026N.p\ufffde\u0012h\ufffda\ufffd\ufffd\ufffd\ufffdq\\\ufffd\u003c\u0003\u000e\ufffd\ufffd\ufffdo\ufffd\u0000m\ufffdg\ufffdzѝ\u001be\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\u001a\ufffdv\r\ufffd{\ufffd\ufffd -\ufffd=\ufffdLCNj\ufffd;\ufffd6Uc\ufffd\ufffd\ufffdZJ\ufffdn?\r\ufffdySF\n\ufffdQv\ufffdE\u003e\"\ufffd\ufffd\ufffd\u0008â~#\ufffd0\ufffd\ufffdh!q\ufffd p\ufffd\u0005\u003e\ufffd\u0019\ufffd.\ufffd\ufffd\ufffdG\ufffd\ufffd\ufffd\ufffd4\u0017\ufffd\ufffd5\ufffdh\u0018\ufffdQ\ufffd\ufffdqwܶ\ufffd\ufffdM\ufffd\u0005\u00165\ufffdX\ufffd'\ufffdF2+:̘V=o 珛o\ufffd \u0013\ufffd4\ufffd\u0006\ufffd\ufffd@֪=\ufffdqS\ufffdq\ufffd\ufffd\ufffdk\\mv\ufffdd\ufffdZ\ufffdN\u0017\ufffd\ufffd\ufffd\ufffd#\ufffd܅\ufffd4\ufffd\ufffd\ufffdى\ufffd\ufffdcg0Vj\u003crk\u0018G\ufffdò\ufffdU\ufffdYW\ufffdT\u001e񇹧׿\u0015\ufffdF\ufffd\ufffdZwu\u001a\u0012\ufffd2\u001e$i\ufffd\\Z(\u001f\ufffd\ufffdO\ufffdH̾\ufffd\ufffdMȠF\ufffd\u001a\u0018\u0016\ufffdjm\ufffde\ufffd\ufffdM\ufffd)\ufffd\ufffd\u00163x@Y\ufffd(;r\ufffd\ufffd\ufffdX0\ufffd\u0008\u001c\ufffd\ufffd\t\u0018\u001eƛtN\u000e\ufffd\ufffd|\ufffd\n\ufffdf\u0007'R\ufffd\ufffd\ufffd\u0006Lu+5\ufffd'R\u0000C\ufffd\ufffd\ufffd\ufffd\ufffd?\ufffd\ufffd%eK\ufffdp\ufffdφ4\ufffd\ufffds\ufffdĹ\ufffd\u0005h,\ufffd:\ufffd\ufffd n\ufffd\ufffd\ufffd\u000eB\ufffdN\ufffdMm\ufffd\u000b\ufffd\u0017\ufffd\u0007i\u0002i\ufffd^\ufffd\ufffd*\ufffdEmj\ufffd\ufffd\ufffd}\u0010zN:\u001d\ufffdN\ufffd\ufffdc\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd{\ufffdݛ\ufffd\ufffdsm\ufffd\ufffd\ufffd:\ufffd\ufffdN\ufffd\ufffd\ufffd\ufffd\u0011\ufffd\ufffd\ufffd\ufffdl\ufffd\ufffd\ufffd\ufffd2\\\u0014\ufffd\ufffd\u0017\ufffdQv\ufffdr7\ufffd\u001f\ufffd]\ufffd\\\ufffdTs0|\ufffd=\ufffd\ufffd\ufffd\ufffdXa\ufffd\ufffd*G\ufffdB\ufffd\ufffd\ufffdw\ufffdz\u000bf\u001e*n3\ufffd\ufffd\ufffdݻ~\ufffd:\ufffd\ufffdޓ\u0012\ufffd\u0005\u0016\\\u000f\ufffdZ\ufffd\ufffdAV\ufffd~\ufffd\ufffd2\ufffdu\ufffdL*4/.sQCp\ufffd\ufffd\u000bG\ufffd\u0019q;k\ufffd\ufffd\ufffd\ufffdl\u0008\ufffd\u0011\ufffd@\ufffdH\ufffd=\ufffd\u001e\ufffd\ufffd\ufffdm\ufffd\ufffd\ufffdU\ufffdg\ufffd!|\ufffd\ufffd\ufffd\ufffd\ufffd\ufffdb\ufffd\ufffdv\ufffd\ufffd\u001f\ufffd\ufffd\ufffd{N\ufffdca6\ufffdI\ufffd\ufffd\ufffd\u0026*\ufffdv\ufffd\u003cz\ufffdn\ufffd\ufffdzg\ufffd3\ufffd2\ufffdp\ufffdލ\ufffd\ufffd7-}\ufffd\u000eY\ufffd\u001cN\u000c\ufffd\ufffdl\ufffd/\ufffd\ufffd_\ufffd\u001c\ufffdpi\ufffd3\ufffd\ufffd\ufffd\u001c\ufffd\u0017L\ni!\ufffd\ufffd\ufffd!\ufffd\ufffd\ufffd\u0026\ufffd\ufffd\u001eqR\ufffd\ufffd\u001ct\\2\ufffd1a\t\ufffd\ufffd\ufffds{N)\u001c\ufffd\u0016w|.3\ufffd\ufffdޞ\ufffd\ufffd\ufffd\u0012o\u0010n\u0004x{m/\ufffd\ufffd\ufffdv\u0005`\u0006\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\t\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\u0005,\u0001}\ufffdD5\u0015z\ufffddh\ufffd̲,\ufffd\u0006\u0014\ufffd\ufffd\ufffd\ufffd\u0013܄|\ufffd\u000c\u001a\ufffd\ufffd}\ufffd=\ufffd\ufffd:Q\u000bI\ufffd\u000f\ufffd \ufffd\ufffd`\ufffdv\ufffd/J7\ufffd\ufffdO\ufffd\u0006f\u000b\u001a\ufffd\ufffd\ufffd1\ufffddza\ufffdQG#]\ufffd\ufffd';\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\u003e/\u0019\ufffd\ufffd6\ufffd\u0000 =\n\ufffd\u003ej\ufffd\ufffd\ufffd\ufffd{5\n\ufffd \u001cn\ufffd4v}dzz\ufffd\ufffd\\\ufffd\ufffd-\ufffd\\\ufffd\ufffd\ufffd\ufffd\ufffdԫ\u0012\ufffd\ufffdƎ|*\ufffd\u000c\ufffdƈظ\ufffd\u001c\ufffd\ufffd\ufffd\ufffdGA\u001c:\ufffd\ufffd\ufffd\ufffd\ufffd%\ufffd+\ufffd\ufffd\u001aՠ\ufffdKS\ufffd\ufffdKM\ufffd,\u001c\ufffd\ufffd2\ufffd\u001cI0\ufffd\ufffd1\ufffd1E\ufffd\ufffdw43\ufffd\ufffd\ufffdq\ufffd1\ufffdi\ufffd1E\u0014\ufffd\ufffdѡ\ufffd\ufffd\ufffd\ufffdV\ufffdL!\ufffd\ufffdl\ufffdaƶ\u003c\ufffd\ufffd\u0012\u0019f\u0012#\ufffd\u0015\ufffdl\u003epY\ufffdUf\ufffdX1\ufffdH|/\ufffdN\ufffdZ\ufffd\ufffd\ufffd|\ufffd\ufffd\ufffdQ\ufffd\u0019\ufffd\ufffdt\ufffdFc\u001a\u0007\u000ci\ufffdXt:\ufffdXo\ufffd\ufffd\u00126\ufffd\ufffd\ufffd0\ufffd\ufffd\ufffd\u0018\u0001\u0015\ufffd\ufffd\ufffd\ufffdRٽ@\ufffd$\ufffd\ufffd\ufffdy\ufffd݂\ufffd_\u0000\ufffd\u0005\ufffd\ufffdUo\ufffd\ufffd\u001c\ufffd\ufffd\ufffd\ufffd\u0012EO\ufffd\ufffd\ufffd+L\ufffd\ufffd\u000f\ufffd]\ufffd\ufffd\u001a\ufffd\u0011\ufffdT\ufffd\u001c\ufffd\ufffd\ufffd~4\ufffd\ufffdꄽ2Vo'\ufffd\u0016\ufffd\ufffd#\ufffdM\ufffd\u001c\ufffd\ufffd\ufffd4U\u001f\ufffd\ufffdmi\n\ufffd\ufffd\u0017\ufffd5`\ufffdL:\ufffdX\u0000\ufffd\t\ufffd\u0019\ufffd\u0012\ufffd\ufffd\ufffd\ufffdr|\ufffd\ufffd\u0005\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffdb\ufffd\ufffd\ufffdw{1ı\ufffd\ufffd\u0003Z\"\ufffd\ufffd\u0019\ufffd\ufffd\ufffdF_\ufffd\ufffdWue`\ufffd\ufffd\ufffd@\ufffd\ufffd\ufffd\ufffdk\ufffd\ufffd\ufffd@\u0015zRZS\ufffd\ufffd\ufffd\ufffdXSU\ufffd\ufffd%\ufffd\u0003\ufffd\u0008'\ufffd\u0000\ufffdL4\ufffd(Ԭ\ufffd\ufffd\ufffd\ufffdlpF\ufffdE,D\u000b\ufffdEVpخ\ufffd\ufffdi\ufffd\ufffd\u0004uad\ufffd\u0004\ufffd\ufffd\u0011/Z\ufffd\ufffd\ufffd҈\ufffd\ufffd\ufffdEX\ufffd\ufffd\ufffd\ufffd\ufffd,V\ufffd\ufffd^\u001c\ufffd\ufffd-\"Lw?6I\ufffdZ\u0001\ufffd\ufffd#\ufffd\ufffd\ufffd\u000b$w\u0018\u0006WHl$ퟐ\ufffd\ufffda\ufffd\ufffd0\ufffd\ufffd\ufffd\ufffd\ufffdO\ufffd{\ufffd1\ufffd\ufffd\ufffdE\ufffd\ufffdO\u0011\ufffd\u00037|\ufffd_\u0000\u0000\u0000\ufffd\ufffd\ufffd\u000c\ufffd\ufffd\ufffd:\u0000\u0000","resp_bytes":2939,"resp_duration":0.979531,"resp_status":200,"time":"2022-03-17T09:53:05+01:00"}

Expected behavior

Something useful is logged. Either print that the payload was compressed and omit it; or decompress it and output the response.

A cheap way out would be to ignore metrics requests' payloads in the request logging. It's of uncertain value.

@srenatus
Copy link
Contributor Author

The same is true when using --pprof and fetching a profile.

@christian1607
Copy link
Contributor

Hi @srenatus, is it okey printing like the image below istead of the current unreadable output ?
image

@srenatus
Copy link
Contributor Author

Yeah that would be much preferable. 👍

@christian1607
Copy link
Contributor

Great!!, Can I take the issue please?

christian1607 added a commit to christian1607/opa that referenced this issue Mar 26, 2022
This change omits the response body when using compression on metrics endpoint and when pprof is enabled

Fixes: open-policy-agent#4442

Signed-off-by: Christian Altamirano <[email protected]>
@christian1607
Copy link
Contributor

Hi @srenatus , I've created this PR

@srenatus
Copy link
Contributor Author

@christian1607 thanks again!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants