Corrupted app-name in messages

[altenhof]

Hi,

I noticed that quite some logs that are emitted from CF jobs, e.g. cloud_controller_ng, scheduler, contain strange app-name fields, like loud_controller_ng, _ng, ot even e.rb or be95020-d783-41e1-868e-5e0769528b23.

As I'm not aware of any component at later stages of the processing pipeline that write that field, I suspect that blackbox may produce these weird lines. Can this be caused by log rotation kicking in?

We're using capi release 1.46.0 with syslog release 11.1.0.

Thanks

Michael Altenhofen SAP SE

[cf-gitbot]

We have created an issue in Pivotal Tracker to manage this:

https://www.pivotaltracker.com/story/show/155032951

The labels on this github issue will be updated when the story is started.

[jtarchie]

Are you able to confirm that all these were coming from the same host? Just trying to narrow down if this is just associated with cloud controller or all elements.

Have you been able to reproduce this at all? Can you provide full syslog message examples?

[altenhof]

Hi @jtarchie,

I don't have full evidence, but it seems that the trouble is related to components that are implemented in Ruby. I just looked at logs from today and saw weird entries for instance group scheduler. Digging deeper, it seems like job cloud_controller_clock was trying to write fairly long logs which got split up. From what I can tell is that this seems to happen at our configured MaxMessageSize boundary at 4kb. What I don't get though is why those splits then lead to corrupted syslog header data. I would have assumed that max message size only affects the payload. Anyways, here are two consecutive (shortened) messages that should illustrate the problem:

<14>1 2018-03-02T12:23:19.015984Z xx.xx.xx.xx cloud_controller_clock - - [instance@47450 director="redacted" deployment="cf" group="scheduler" az="z2" id="f8450bfd-1bb5-41ad-8ad7-9d0ff30be3e6"] {"timestamp":1519993398.4427812,"message":"(0.011373s) SELECT * FROM \"buildpack_lifecycle_data\" WHERE (\"buildpack_lifecycle_data\".\"app_guid\" IN ('2d3dfe7e-92f9-4d20-9366-1cb4d6ce493d', '2425a888-5865-4ce7-9b1a-dbd926a51029', 'fab2ef98-5a0f-444c-a160-68a8939103e4', 'b6f103f4-d9ac-45f8-b0ad-48367330bc31', 'aad744ef-bd00-4818-a48b-cd4fe006be2c', '8729615f-cfbd-4b14-9082-377af5c4a0df', '6c2d9d88-f9d8-48c2-8378-d1a5f82a62d2', '3e5931d6-e4ef-4def-872e-14036b4d4e9d', '5622e026-ec9c-4194-adf8-4a70c7e72907', '3a401f33-a897-4345-8661-6669b6333410', '0cb69cc7-720d-4a6f-bd5a-d352ac6ca7ba', 'd8b2fdb5-f3af-4a1f-bf13-b870bb3f3680', '3a22cd28-e0d5-4e9d-9076-b910e98fe3f8', '6dc337fe-5250-44e4-ba97-8fed195e39d9', '7503bed7-7838-4a50-b36a-3832fa6546a1', 'af090dcd-2eab-4b72-87f9-362b76909181', '33979ade-0815-4e0b-926a-e6b0ebbc7a6d', 'ece74bc3-2ba8-423c-bd9c-d02feef296b1', 'e2e51e03-911d-4206-b4fa-e22df6c6397d', '61473d1f-96eb-4f7f-9c08-9e1b5b1cdfdb', '0ccfd982-b0c7-400b-b697-97a96de8633a', '85ac628b-194e-44c5-9375-026c340c56eb', '489b1d31-422a-478f-ad46-726f559ce51f', 'c0fc7350-399a-40b3-99fa-9de8958f227a', '5a3812a7-d94e-4e83-b84d-742fb86e90b4', '30655969-7daf-4e49-8d39-fec818f27635', '3dcfd635-c64c-4a18-8abd-8589d9a12671', '49c937d6-1a5e-4fdc-87c2-92bafba5f5f9', '8d9f16dd-0ae6-4b5a-b279-5d1340bd6c7f', 'dd67898e-9a3c-4504-b553-b3ae0ec5255d', '91b58149-7557-4d0c-946c-e629af7fa5bd', '05d06cdf-a4c9-41d9-b436-185cedefe6b8', '731f83fc-6cb4-4083-92e6-ab07b22207c6', 'fa7a12d8-5f2a-4bfd-bb93-a1dd57e96c15', '57a55f25-4bbb-42b3-a46d-0e8061d2eee2', '1881f396-e077-4ca4-b804-7b71d55382ec', '1c27be4e-987b-4137-b67f-19df9937c35e', 'a1602e35-d650-440a-9ba3-1976d299a592', 'bc6bdaf0-69e8-4366-8783-01e117bbfc55', '438cc2af-628b-4181-898e-b48b425d198e', '89a1a7a1-7196-4433-9a06-3c04dca748f4', '17da5a47-e8a3-4657-8db2-5804e36e2540', 'bf1f6e37-4591-4e43-aef7-45cd454d96cc', '5705dd2f-5a9d-4b24-b33d-4d20c28e5a8a', '2841e131-a80b-484b-8906-9c0d475d0a1a', '0aa4351e-4212-4fe9-b946-78c3a0fad29e', 'c45024b9-34d6-4267-a51a-1a8c2e156b51', '13cc5b9c-379e-4c8f-b052-1fce7620518f', '72580589-d8e3-4b4a-b8cd-dd5a4dd522a3', '0d77190d-4de6-420e-a4fb-a973e70b57ae', '49076843-b96d-434c-8485-62aebd6312d6', '5bcb1694-4754-4885-bb8f-a9362ffb62e6', '9d20e39b-60a3-4dfb-97e5-4ad13cee2f17', '93d6b5d4-8226-4f19-8c3e-03ee92b96af4', '19e431ac-043e-40bd-9e24-8f40ba2e65eb', '268bb7b7-2607-4522-9f56-ea0bd74bee95', '04d0935d-6b29-4b11-9cd0-e39e8c69e1f6', '1b6f3df8-02df-45d5-bbc2-db525143ea2c', '324daeaa-cc95-4939-997b-b4bcea31bd38', 'a3f460d2-84ec-460f-8326-96a38e2b00e5', 'd43b769e-519d-44df-8dbe-f8146b18bf76', '78bc9435-ea67-4fb1-9399-6984558a6f8b', '3907d18e-3adc-4202-87da-d6dc1230d179', '82ca8148-82a6-4442-bea1-2f1f5fe42a93', 'fa6f5d96-f7f9-4f52-b102-f76b41bb3f1d', '4734accf-dc03-4c00-989f-53bc1780c04e', '5b81d7d9-e486-4869-950d-52a2d08e194f', '4bd0574d-d8aa-487e-9640-141900dd4204', 'b7ebe488-da28-4af2-9c18-a2504ee231e7', 'bbb1aa74-6fb2-48a1-904b-d34436f3ca36', '7a13d08d-3f88-4cde-a99c-91b9c7322b03', '0f1641ca-2e46-44e4-b0b8-7b9b0a7c5d8c', '41036d93-485e-4045-9c3a-4510c65f154d', 'b21f8c7f-ccc2-473a-bd48-1aaa4b1ec8fe', 'b148fd6b-7151-4a63-ac8f-6fe739864439', 'f4e6d5b0-7413-4954-a3f4-477af64db7f4', '8bbf6c12-5af3-442b-86b5-ba72fa7f4246', 'de766f87-d922-40d2-9d0c-67a82457750d', 'f07b2c70-2146-4ba1-b45d-fe565cf03b58', '41f69055-d4ed-4215-bade-5545e0d33eba', 'eab7c4a6-99b6-492e-bb24-a760e0f87563', '1e6d01e5-d670-4801-b30b-8c6301fe9d69', '60f0d065-89b4-4e2c-a4a1-d884d1310396', '6ec980e1-0f4f-4ac1-b21c-0c66218eb896', 'be735256-e43f-4083-afee-97f9264b4b0d', '65cba446-7ab8-4d19-b064-61fa41f8cee7', '7cecfcb3-fc73-4a56-9a36-883d5bcbe2b0', 'b2fe06e6-1056-437b-83b8-1957877fbfe4', 'f9846409-2a4c-42a8-954d-dc2b982adeed', '5c91d21a-ae24-49d1-a8a1-681fd7d7b799', 'bb752cd7-d61e-44cb-b56b-cf4df3ca3529', '86b8fe43-4144-4faf-89df-112f6dfa9d6b', 'ac6e61ed-1814-4fbf-bb2f-d4c079166c67', 'c49d5621-9dbe-4ede-af74
<13>1 2018-03-02T12:23:19.016909+00:00 xx.xx.xx.xx d7f-92a2-0fa5151ae660', - - [instance@47450 director="redacted" deployment="cf" group="scheduler" az="z2" id="f8450bfd-1bb5-41ad-8ad7-9d0ff30be3e6"] '7908d5fd-5744-4cfb-9293-0716d3a8ac25', 'a809fab5-b930-4aae-98f8-3f947c2db77e', 'bf186d6c-9b5d-488f-8da3-2348eb41929e', '247836cd-57bd-4dda-b52b-46e38434090c', 'b3c7e350-40bf-4b7b-8ce4-68e84015e9c8', '6f9d496e-a995-4641-83bb-cd794ac27f7b', '1852d17a-952e-447d-a59d-2f7ce9786ef2', 'a87e4e81-918d-446e-94b9-6eba2d2b4249', '559f9b4e-68df-466a-9f11-1bd50f058f6d', 'eedd79d9-c500-4055-bca1-df2f1640f213', '4e935d2a-994a-4a73-b938-11c6d82fe3c8', 'db6830a2-e6c6-4ef7-9a24-9c055d9d08fc', '8b73434a-1100-452a-a03a-90e66f5f0148', 'd232064d-0ade-41d3-a814-27d4a9696321', '295eb3cb-d27f-44f6-9d7b-f70a23656ea6', '52ebb32a-4672-4a2d-8c6a-09dd799d6d9d', '7fb1244c-2ab3-4138-942e-759fb8f835cf', '975a4643-a5ba-445a-8686-04c9443498c7', '5f192daf-7653-4866-a776-68ce5b45c90f', '4551af92-543d-47a2-b956-7ecc14d7e1e0', 'a8b47065-59b8-4c7b-819c-d17978c3dec2', '5f3f629f-3d2b-42d2-8490-58eae41baacf', '859d8863-5923-49b1-ac74-6c3d1f4b921f', 'fb305ef6-9d63-4a87-9bbd-8be8309a960f', '675108dd-3116-4629-a729-a3d20bb88709', 'b0d7ed6f-ab88-4f21-894e-6637255729c6', '0cd5c58b-00ae-4f23-886c-1b3ae69b7bdf', 'f146fdd0-0999-40da-b195-130b810c39da', '49efb25d-ddd0-4993-92ed-4c0ae6856ee7', '89476474-1ea1-46f3-a6e9-56c110c0a763', '4fe25ff8-3dff-4865-aa5f-99ab2699fcef', '299cc34e-10fc-447b-b909-1451a165bb12', '0fb87d34-2e29-4203-8862-15199722937e', 'fcaeb8db-37fa-40aa-a9b8-786732b17768', '47843b36-fd99-4444-a426-d27865b26a7a', '45bdc6b4-55bf-4c2a-ab2d-306dd9da9323', '3bcd74f1-2539-4ded-b33c-5e0990f1c702', 'be14b4e5-3435-421d-ba26-d4fb2b95ce55', '7b87f80b-e143-45c8-9876-7f42fed6bd4e', '5593f7ef-bf48-442f-b4da-8cbef839bd9f', '9d4f4164-b93c-461f-a9e5-7b1532482396', 'd06e00d5-f461-42a7-8153-7c71185e0106', '205d384b-db8e-4b40-8457-58e3b824e138', '49646090-2a55-456f-8aad-90c6b4a683f5', 'cde874c2-8946-46a3-8756-b39bee7ea51f', 'da572ed7-ac97-4514-940d-f0878929fefa', '81ced72b-3413-4bff-a587-6220f3eb48e0', 'e46cd915-8c9c-4ee8-9dd5-c0f05775c9d5', '623703db-416a-454b-80d8-91d7a55c1224', 'acef517e-0457-47b3-8d95-554d5f675065', 'ffa574a4-cae8-4b3e-a862-c4928ecdc9e9', 'aef8e1ea-f41c-4e59-86dc-6bf68c8139eb', '8f124675-8860-458a-9bbe-e6f6874428a1', '09f167f3-6a24-4221-907a-64ec64aacdfc', '9b2a460e-2221-49c3-a2c4-bb91a7d2ba20', '423233d7-cc06-4d9f-82c0-9ed91923b7d3', 'ec2601da-105e-4c31-8deb-56c41ece7dc8', '4795f3f4-c205-4270-ae08-d60797bed98f', 'ca89d69d-27b6-4bd6-bc90-44941ab223fe', '49a6124a-e2fb-4e5e-8305-aab6d1360d14', 'ee636ca5-334a-46a2-bb53-d2845bfbb761', 'e66a78f4-1f6c-467d-86a8-0d4d00115e16', '51f31a20-d390-4d44-aec9-064d0e4d35c4', '9559a8a7-1081-4437-8d33-043819acb4cc', 'ebe16f98-3875-4691-9964-abf3b3373465', 'd230390d-0d70-42ff-be97-e72bc9bd695d', '9f29887f-0e42-4e7e-a103-6ab293745b2d', '371100bc-eb4c-44e9-8ac3-568717709737', 'eb1b8f88-a886-475f-a491-24214c286f77', '67b11941-7c91-4775-9924-fc95d79da4d2', '471a27de-4a5c-4b53-946d-46bfaa864534', '0a8c8db5-1241-4875-98bb-b009bef3ad3a', '656a0675-3291-4fdf-bf78-a124c817bfbf', 'b0b395df-44fe-43eb-8a75-d09970eaa77c', '9163bfcc-f94d-4e9d-98bf-dd7818d3981d', '3688bae9-1a83-478e-b93e-24252930c351', '73edb472-4b45-4758-8505-cf4398cacdce', '75fcb7fd-b855-44d5-936b-a311cb43126b', 'df430e67-bb02-4c38-a172-0992168e029a', '302b18a6-5fb5-4769-a831-08af831a45b6', '9a736be2-c550-42d3-85d3-5cfbe951d99b', 'e06d5163-c4ec-4bbe-ac63-cd99dcc81d10', 'f70467f1-15fb-4b94-a9bf-1da669140cf7', '8b390258-dd70-43c7-8a54-469b33645a5d', 'fd65504f-f2bf-423c-83cd-7126f72bfdc6', '43cbfe26-47a3-4bc3-b861-a7931519df58', '0e3bc3a2-9535-4fd2-96df-1a81c5816056', '548c5531-c63b-4f8f-ac7b-ec45c6c8d1b9', 'ec91d8e2-8950-4b6e-82d1-90116abbffd4', '659b51dd-11b7-4cac-9f9f-dfb9771d8d40', '090bb137-2b65-461a-af90-32f2f1f68297', 'e0ba4840-abb1-4750-a787-b67e59ac9962', 'bc49ab80-d1c1-4d3d-ad4b-b96cd3ebafb2', 'd7ebc18a-6922-45bd-b356-047e7b6992fa', 'd43d77d5-2d63-4be5-a62f-e02de8a44052', '259784d5-2133-4b2b-9a83-c3d97c20cd47', '08b330b4-7645-4557-ad6b-e32c2eaec7b6', '8b3ccccc

Note that I do also see message sequences in the same time window for the same job that are split as well, but where the header data is not corrupted.

Best Michael

[jtarchie]

We spent some time investigating this today.

It looks like this is an interaction between blackbox and the $MaxMessageSize configuration option in rsyslog. We're not sure exactly what is happening, but when other log sources (logger, remote rsyslogs) hit this limit, they behave differently-but-not-crazily (logger truncates and rsyslog splits the message without resending or messing up the structured data). Blackbox, by contrast, appears to split and resend the structured data, except with some fields replaced by an excerpt from the message.

That's obviously not what anyone wants.

Unfortunately, this also looks like something we'll need to ship a new release to fix; the way syslog.custom_rule currently works means it can't be used to work around this. We're also not sure exactly how we'd like to approach fixing it, since we intend to eliminate blackbox as soon as practicable and there's a memory-use implication for increasing $MaxMessageSize.

So, we'll try and at least have a workaround option for you in a cf-d release soon; a real fix might take a little longer.

Thanks again for reporting this issue.

(Signed-off by @anEXPer )

[altenhof]

Thanks for confirming this issue.

One more thing: I know it has an impact on memory usage, but I really would appreciate if I could configure $MaxMessageSize via a parameter, too.

[Benjamintf1]

You should be actually able to set this right now using the custom rule section!

When we said you couldn't earlier, we erred; while we had changes to how it worked on the develop branch, those changes are not in 1.11.1, and won't be in the next release. So as long as you're not running a dev release from a brief period of time, you can configure $MaxMessageSize with syslog.custom_rule.

Longer term, it looks like when our configs were written, the rsyslog default was 2k, so 4k was an increase. It appears that the default is now 8k, so our rule is actually making it smaller.

Our next release will probably just bump this to 8k. You'll still be able to override it.

[Benjamintf1]

Two other important things to note:

1. We are working at remove black-box and using rsyslog to track file changes. This means that many of the issues related to this will likely go away.

2. As you raise the MaxMessageSize, if you are using udp, the risk that your message will not be received will drop. Rsyslog suggests that you limit it to 4k for udp messages. http://www.rsyslog.com/doc/v8-stable/configuration/global/index.html

Note: testing showed that 4k seems to be the typical maximum for UDP based syslog. This is an IP stack restriction. Not always … but very often. If you go beyond that value, be sure to test that rsyslogd actually does what you think it should do ;) It is highly suggested to use a TCP based transport instead of UDP (plain TCP syslog, RELP). This resolves the UDP stack size restrictions. Note that 2k, is the smallest size that must be supported in order to be compliant to the upcoming new syslog RFC series.

We're still figuring out exactly how we're going to address this long term; with the removal of blackbox this particular issue will likely end, but setting max message size appropriately for the transport protocol is still something we'd like to solve.

[Benjamintf1]

@altenhof Are you manually setting the cc.log_db_queries? Is this something that's important to be forwarded?

[anEXPer]

Context on the above question: while we're tackling fixing the behavior, we're also following up with the emitters of these very long log lines to find out if they're necessary.

So, any information you could give us about what jobs are producing these logs, especially if you can include example lines, would be very helpful to us. They appear to be scale/load dependent, so they're not necessarily easy for us to simulate/explore for.

Thank you again for reporting this issue; we've learned a lot about the behavior of our components by investigating it, and it's informed our thinking about various technical ways forward.

[altenhof]

@Benjamintf1, as far as I can tell, cc.log_db_queries is set to true, but I cannot actually judge on the importance as this piece it not maintained by me ;-)

[altenhof]

@anEXPer,

as far as examples are concerned, I would suspect that any Ruby code that does log_db_queries is a candidate. As I mentioned in one of my comments above, I see issues with the scheduler instance group. There, cloud_controller_clock, e.g., seems to log that it does some checking on buildpack-releated info. I'll have to dig out the full message.

[altenhof]

Ok, here's an example from the cloud_controller_clock:

{"timestamp":1522306813.3287106,"message":"(0.003500s) SELECT * FROM \"buildpack_lifecycle_data\" WHERE (\"buildpack_lifecycle_data\".\"app_guid\" IN ('ba97ba24-e574-416b-9f7f-129796c69abf', '5b4d8af0-7f42-4544-85db-40dcb16fb751', '9025f265-8657-4285-9723-9c9eef4df90d', '97049776-e079-459b-8591-31cee9d2c35a', '8a01cd60-ac69-416c-8909-949bdb0ec853', '1b66a9f5-127a-44f8-9faa-dadf9dcfba0e', '0d46ec3e-c970-4873-8e8c-049d537f32e0', 'c5ada9ac-3d6f-4220-9b91-a67247ca2b99', '3ab20d49-d5cd-4b03-9a02-6ed4ff4c4980', 'aa18d2d4-e10a-4a4f-88cc-ce7bd355262c', 'cb70a5ed-22e2-4b26-af4d-98b2f663c580', '669f9958-6c20-488e-af90-d645f04c508c', 'c7e4b521-cf2e-4713-8500-2ac09e733b68', 'cf3120a9-473b-4d67-846a-959eded31e7b', '32613183-a079-4df1-85cf-008838d8a95e', '5abf394d-506a-46fc-acd2-eb2940a251c4', '23839e7c-a36f-4796-9357-af7270f79359', '6163b369-95c6-4391-b16e-9b8096522a03', 'cdff3526-073b-4edd-a369-aebad7786177', '7fdc0cd9-66ba-4e8a-a289-4c8ae6a327d8', '12fc2d28-36be-4863-acb3-6e63f23fbfd4', '51541036-66d9-42a3-85e7-1bbbed945a95', '9c049b44-7feb-4f63-95dd-cc2e831dc6ca', 'd112a5e9-1e4e-4bfd-860f-21daf91a313e', '3085f400-726f-40be-a5b0-b0bb26e759ab', '2ce6439b-c9ad-4f03-85fe-e97c6a9f98b8', 'b0912b56-eb38-4430-b6bc-ecdb8da6bbfd', 'a33810ef-e6f8-4d32-a2ae-56b808a1f7cf', '93144bb7-daf0-437c-82cc-14a4d803165f', '18f14f12-73b2-4ad3-acd9-e9ec88c745bc', '3947fc46-0fd5-4851-aa80-4660fcde2459', '0011d417-dd91-4a46-afb5-d3d0aeb76264', '029deb43-d32f-4305-8fe4-1f585d300c5b', 'a3e47f7c-62a8-42dd-908a-90102c473dbd', 'ec733625-5645-4460-ab05-e7760f536ef4', '44f7a6db-29a6-4de0-9efc-97b49c8480df', 'd77a1507-1c13-4f9f-a200-10167ded3a0d', 'f025d09b-8a82-46fd-92e3-0bc857a0da5b', '16458988-0613-4e8c-981c-a365ba638ca2', 'a99c8f12-b6cf-46d9-947a-958158d95c28', '2d33d663-ff8a-429b-9bc5-835362247d9f', '8214ba53-42d5-4257-899e-ab5fd86fec1e', 'cc593981-b7a1-4208-b65d-763370fbc075', '9011a0b1-dcb6-4ab4-9912-c8ba3cf3d098', '5bfa1954-1134-45b1-95c6-c4a6d00890b8', 'e6a95991-1004-4897-b099-2628cfc5c68e', 'b59d029b-16c5-47ee-94c5-28409fb33eda', '63d8b918-35fa-4712-b1a1-7279a737bdbe', 'cd4a826f-ee9b-4d03-9975-d3ac35c2636f', '4c8aa2ff-824e-4942-a7e3-397f69a33090', '3f2b8bca-d305-427f-b27a-5e7db6aae551', '17c767be-74f6-4c6c-9c61-b9089eb09646', '2fd53f31-babd-4052-9dac-ae5461612110', '7f0efdbe-43ae-4534-b179-96712dac66f1', 'b6275ae3-a4f2-4d00-a780-35679ced27a7', 'd87c7280-a93e-4421-b83b-c7b8aae56c53', '422d5e0f-7b86-410c-bc2b-262065399156', '95de4329-4f87-4172-82f0-88da007e8309', '42b5be38-1061-4492-bbc0-dd53b5f1f72c', '20dc3bac-c70a-4855-b394-46d7604dffc6', '6a7bc11a-9bad-48d5-8fb3-285b81b4dbab', 'ad31dba4-426b-4cec-a5c6-4be80cf0f68a', '06a2a0ab-050a-49b1-8726-a570efd5a783', '72ccf325-145b-4855-a9d2-18b3484b8df6', '50bf53cd-7551-4994-9e29-55071a19acc7', '72bb2908-6770-4dc3-b5a2-207701737db9', 'd6b04075-27b1-4b0c-9a52-536d241b556c', '9d0829f9-926a-44f8-a450-8e6ad73b7436', '91effa01-8b3f-4944-bcf3-a027aa1b5eb0', 'b093572c-8867-4a3b-aaed-f5090b055ab7', 'db0a23ba-f950-45aa-8ec7-50477a8cd618', 'df9b76d4-5ec8-43ca-9dc5-760d424e3647', '03b4e2e4-1a59-4b6e-a46f-ffd6216f1aa6', '0e216bbf-eae0-43e5-8ddc-f14c11fbfe1b', 'd2f84aff-34bc-48cd-964c-1383f2ff7773', '72d097fc-e353-4c7d-8907-6b8fefe7d53d', '3f3a9ae0-25af-4514-b5b3-a3035da08dc0', 'cfef6727-e609-473d-bb9d-3bdbdf1811c2', 'da6a3a80-0a18-4a3d-90d2-543cd87bda03', 'df12a64a-abef-447e-8901-01591718f895', 'f459722c-058f-4829-9600-7cbc50307404', 'eeb7c856-32f5-4fa9-b62c-651ce70470f2', '1e16a428-0749-4b46-b2fc-9d40827335d0', '941a5997-2088-418a-b10f-30fae1ed2644', '6042c95b-deff-457e-9d25-9ff77fb23017', 'cc31b484-6283-4f5f-9551-07bca34a2215', 'a11872e6-0f68-46da-9513-b18dd84786f7', '0e6720d2-c41f-4835-8b79-3315ce8244ef', 'c2bc8d51-d1f8-4681-aa1a-0c4af4ee3300', '8c0e1817-9250-4d7d-a37f-6d94801aa0c2', '529e15dd-b9f7-4a3e-ba93-a1f5b35a5cf6', 'd52157a9-66dd-490e-8c2e-dfe6f218bff3', '97826b97-70f2-491f-a7d9-ee180de4a33c', '0d9a7eae-4fef-4d03-b1fd-ae89b5ed1bd3', '600c706a-7d4a-475a-805d-5078e5024c7b', '09b3ae86-e79b-498c-889c-0b7db560dcee', 'c6758867-deac-4876-8ff6-2c2558ee8428', '36e487f0-ab91-4c25-a868-2a69c0698845', '01734d12-c221-41de-9e5c-c314be29782f', '5d92c3e2-cf6e-4da1-8119-bda12d11c86f', '60cd6732-0f7a-41df-88a0-595374998d66', 'fd6d986d-6438-43b8-b5dc-cf1529d7ed7a', '10a931e9-bdcf-4b3a-84db-447fbf54df4d', '6c2fd886-506a-42c6-a269-df8e45fe733f', '73e6af1c-34a0-4b96-976c-99d43e5cf715', '416e094f-8715-4703-b5f1-e450ae8b6ccd', '8175cb57-fbfc-4217-8a0d-6b8d631d73a1', '09644104-16a6-4129-beef-fd6f25bcef0c', 'cb9f5150-8244-4c8a-8268-12b6f6a52a64', '3a181f4f-8926-46ec-8a56-6f1235170486', 'd1154254-396a-48ad-9b8e-36444b716c77', '4e52def0-2042-4888-8c16-41ac81c76a7f', 'ed2e42d1-ca62-4e30-8e12-715112433570', 'a6b90008-f1c7-476c-8e4d-f1f2fe7b054d', '71a2c546-f225-4b04-b282-b15ab97f1f28', '0cb1dd88-7d3c-4793-b767-acc4ce18ebb7', 'ad8d9797-5fcc-4269-9b0d-2409bd14540a', '8e7ade90-aa30-4f69-8af7-298cb4a5b76c', 'bfd6950d-8eea-460b-b812-a4be180afc33', 'd21951d3-b140-4ffb-ba04-ae7c637e6549', 'e2f365c6-f4c9-4bfc-b331-d77472abb732', '01bffdc0-47e0-49c2-86f4-70aa9681c9f2', 'bfdaf8de-1647-4bd6-a958-1f2c42476751', '3a33b673-351c-49bf-ac02-71d871e24046', 'e9961ad1-8fe0-4fd9-921a-2bbbdc812629', '4cc4c1ef-5947-4745-8ede-bec8e0eeedc3', '68e30599-3e1c-41e4-be87-b87f84f60b54', 'cf665748-1a83-4998-b7df-4dc3222b2081', 'd0eee7f3-f199-412b-8933-432cf8ac83d2', 'a3924562-6ed4-463f-93e1-d6e5d357e61f', '2308f65b-87f0-4ba8-be78-9bed04389278', '4e28146e-c3ec-4a41-8cf5-c1bd4feb9025', '11acd22b-4efe-41ac-b585-f45cfe22ecff', '4377ee4b-da6c-4c76-aed5-770817f183c2', 'c7065c66-758c-49a5-8bfc-44b952c9c539', 'de03ec2c-5141-441d-bc76-6538b5d97d15', '8360b2d5-ec68-496e-83ed-b497da48e3c5', 'b5a2f8d1-7c24-4ff3-8051-387eba049387', '39abfee8-b1ea-4780-a8a0-5ad745032426', 'dcee3077-7d56-4bae-acc9-5169be7282e9', '13b29ea6-14fd-45a0-8779-9e1973ac9bbc', 'f605e4f9-1f78-43f6-9986-67b8bb82e846', '45a6e060-6393-4d8e-8fc8-6f0df766065b', 'f6313b5c-0b74-4d39-81da-614f46b86213', 'f931b6b6-6805-4426-ac8e-d03d94acd687', 'ec5dc2db-7f35-4866-ba1e-0681116f0eeb', '68ba0856-a5ff-4a25-8aad-bde93c100994', '5d44be58-082f-45a6-8b20-4f612c9170c9', '605fad7e-8a65-4067-a268-a3bc38cd3085', '3eba9d7a-53a2-4d61-9a3a-7bc0c53dffaf', '70941c4d-e142-4025-9a85-56ea955da2bc', 'fcd88947-6f32-41bf-8908-d65ef6580dfd', '54b49cbc-e69c-48ee-ac11-7f95a514d34e', 'fc33d7d1-490f-4213-a055-46e80b1c1ab0', '85445cd7-a675-437c-aaef-f18cba4260d7', '38707523-fcfa-45ec-a278-cfb54abda385', 'd09ee281-cf28-4183-8db6-b3db39cab215', '2488af37-de34-4c8c-9cce-9d423ef6bb7b', 'aefc9536-44e4-4bd1-82e7-875aa8b13641', '8ea897aa-9ff8-4cf0-b22b-736d68a16c82', '80267ebd-11f0-44af-87d4-882be6104706', '07157cea-3df7-44a1-a104-63433ba701fd', 'd92cffe3-848e-4d45-93e7-16b1f13ac9a4', '645ab0b5-e318-4361-b338-a9e07e41f608', '5efb9e29-1058-42c3-b86c-dc42c113a677', '478c5326-d6af-47ae-9f0e-27fdfda48061', '36ab5fc3-f037-4e6e-97ba-b8fd352b9c83', 'b6f78898-28c6-4b69-88ae-c0ec028e6af8', '621aed09-6187-4f05-bacc-5072e55cf595', '8a1a28ac-7fbc-40f6-8477-d45d4ae10c3f', '3b73d4c0-6007-4847-b580-07ce147a2d2a', '078461ff-4f67-44ad-ad49-c90fe162b562', '29016f13-9feb-4ae5-856b-11fb256cc437', 'e41d035c-c0e3-4baf-a0de-20efa1057311', 'def18710-867f-4a45-bec7-f64064541ea1', '674d18a4-e831-4baa-8bdf-c4cad4265f6f', '762e27b9-9633-4a6e-b9b2-69c673285bc7', '58361a89-95fb-4f92-8b55-5732146e73a6', 'f9044430-9e93-422e-b905-afc20d084aee', 'd6d0a8a1-6cd8-4dac-b48c-12623d8e9046', 'b90c2bf2-6265-4fef-9374-e4c99cb38911', '47c5c737-2d6f-407a-81c4-a94245691636', '3231abfd-8cd1-4a3e-8f35-7776ac1f7e49', '03d3366a-f2ce-48c7-8247-48a203809a57', '5e53a997-21c9-4c8c-929d-1bc1187fd8ed', '8f911518-c51f-43f0-97be-602d316e7d3e', '1a7ad0cb-a394-4551-a100-8cc97ffd65fa', '58e60105-0ba7-496c-a726-eeb797cbd68d', '5744fb46-5be8-4612-8ef9-e8010525181c', '46a89774-dfaf-48f4-83d3-1affb43a2ec0', 'a4b9a896-5b71-44e1-818b-22a9e3a548cb', 'f952dc27-740f-462c-86e0-154eeb89eb61', '2ac3f413-1d7e-42f7-b5bc-8e21914e4c40', '88bc7ecc-78b3-4edf-abb3-0da291d91e77', 'cd3d164b-67f4-4d7a-b97c-1859da7eea67', '00fb20a0-88f4-4368-bd9c-59e7c2f82ba5', 'de52f65e-c17e-467b-a27b-4d98e1463f6c', 'da4ba454-e5a9-42d8-9bb3-d52018e9811d', 'c8dd05af-beb9-4ee1-b713-7bc600eead89', '902b0719-b754-461c-b666-bba410efe06f', 'bac870ca-be24-4a03-87f0-667c073014ef', 'c522b89f-51fa-4568-a38c-2829b6863d74', 'b08e856b-5ac0-45df-9573-d04d957c8386', '4cba1809-4e08-42bf-aa32-29a3f8a04849', 'beab53a2-46e9-42ae-a6a0-d94336c7575a', '94fdc7d0-5845-46c8-bc83-1e6e85c92de6', 'ad3e6fc4-9dc4-4ecc-90d4-fef8ba196dab', 'f57aa64d-ae49-404a-8d7b-8cf596eb2085', '7b2e2192-2645-4e1b-ae07-8450963fa436', 'bbd466d9-0e2b-4e99-a51c-f6f56db1a529', '84965e1a-d061-4e91-95ae-c25a06f69695'))","log_level":"info","source":"cc.background","data":{},"thread_id":69878550238040,"fiber_id":69878550234660,"process_id":24653,"file":"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.4.0/gems/sequel-4.49.0/lib/sequel/database/logging.rb","lineno":88,"method":"block in log_each"}

But there are a few of them, selecting from different tables. I guess the key to reproduce the problem is having lots of apps deployed.

[anEXPer]

Thanks for the followup.

It looks like that's the same query as before. If we've just got one property that's basically "turn on giant debug lines" across CAPI-related jobs (or even just on the CC's clock!), our first recommendation is turn it off. Well, stop specifying it, really, since the default is off.

We're glad to know about the corruption of long messages, but the emission of messages of that size is in itself a concern. When we raised this with CAPI, true to classic doctor-joke form, they said, "oh yeah, don't turn that on."

[Benjamintf1]

Thanks again for raising this issue, @altenhof. We're going to close it, but want feedback on our resolution.

We're adding documentation to our custom rules doc specifying that it can be used to override $MaxMessageSize. As long as blackbox doesn't hit this limit, it doesn't corrupt app names. We hope that's a good-enough workaround. Is it satisfactory for you?

Longer term, the two underlying issues seem to us to boil down to "remote_syslog2 handles hitting a receiver's max very poorly" and "some CF jobs emit log lines that are unreasonably long." We can't definitively solve either of these immediately, but will push on both of them. And the particular log line that's been hitting you is already off by default.

[altenhof]

Sorry for being late with my reply. I'm currently busy with other things, but we'll certainly give the custom rule thing a try once the documentation is available.