Closed jwreagor closed 6 years ago
Sorry about that! I'm not a Go programmer, as it's plenty obvious. In hindsight, I guess the empty write comes from the return b that is never used. Did you try getting rid of the 'b' declaration and return? That might do the right thing.
@mterron No worries, it is the nature of programming.
In hindsight, I guess the empty write comes from the return b that is never used. Did you try getting rid of the 'b' declaration and return?
You are correct, and I also believe the fmt.Print
is also suspect in that it is side stepping logrus
and outputting to the console itself. We actually want the buffer's bytes to be returned and logged by logrus
.
In my PR so far I've removed the extra 0-byte writes by doing the timestamp replace in line but I'm actually duplicating the timestamp right now. I need to fix that before merging.
I feel like we're going to rip out logrus
soon anyway so I needed to do this work to find edge cases.
I've added a configurable attribute for the timestamp (for future clarification).
The following Dtrace confirms the 0-byte writes are gone and fluentd logging is functioning properly.
265239832136014 7695b8af logger[88600] syscall::read:entry(4,/dev/zfd/4,4096)
265239832177464 7695b8af logger[88600] syscall::read:entry(3,/dev/zfd/3,4096)
265239855152833 7695b8af containerpilot[88608] lx-syscall::write:entry(1,/dev/zfd/1)
265239855223066 7695b8af containerpilot[88608] lx-syscall::write:return(1,/dev/zfd/1) = '2018-01-05T20:20:35.129030056Z loaded config: {\"Discovery\":{},\"LogConfig\":{\"level\":\"DEBUG\",\"format\":\"default\",\"output\":\"stdout\"},\"StopTimeout\":5,\"Jobs\":[{\"Name\":\"consul\",\"Exec\":\"consul agent -dev\",\"Port\":0,\"Interfaces\":null,\"Tags\":null,\"ConsulExtras\":null\0'[767]
265239855240178 7695b8af logger[88600] syscall::read:return(3,/dev/zfd/3) = '2018-01-05T20:20:35.129030056Z loaded config: {\"Discovery\":{},\"LogConfig\":{\"level\":\"DEBUG\",\"format\":\"default\",\"output\":\"stdout\"},\"StopTimeout\":5,\"Jobs\":[{\"Name\":\"consul\",\"Exec\":\"consul agent -dev\",\"Port\":0,\"Interfaces\":null,\"Tags\":null,\"ConsulExtras\":null\0'[767]
265239855249544 global zoneadmd[88429] read(16[/devices/pseudo/zfdnex@2/zfd@6:master6],1024):entry
265239855309571 global zoneadmd[88429] read(16[/devices/pseudo/zfdnex@2/zfd@6:master6]):return = '2018-01-05T20:20:35.129030056Z loaded config: {\"Discovery\":{},\"LogConfig\":{\"level\":\"DEBUG\",\"format\":\"default\",\"output\":\"stdout\"},\"StopTimeout\":5,\"Jobs\":[{\"Name\":\"consul\",\"Exec\":\"consul agent -dev\",\"Port\":0,\"Interfaces\":null,\"Tags\":null,\"ConsulExtras\":null\0'[767]
265239855517736 7695b8af logger[88600] syscall::read:entry(3,/dev/zfd/3,4096)
265239855576784 7695b8af containerpilot[88608] lx-syscall::write:entry(1,/dev/zfd/1)
265239855640758 7695b8af containerpilot[88608] lx-syscall::write:return(1,/dev/zfd/1) = '2018-01-05T20:20:35.12961581Z control: initialized router for control server\n\0'[77]
265239855646928 7695b8af logger[88600] syscall::read:return(3,/dev/zfd/3) = '2018-01-05T20:20:35.12961581Z control: initialized router for control server\n\0'[77]
265239855730004 7695b8af logger[88600] syscall::read:entry(3,/dev/zfd/3,4096)
265239855930981 global zoneadmd[88429] read(16[/devices/pseudo/zfdnex@2/zfd@6:master6],1024):entry
265239855969357 global zoneadmd[88429] read(16[/devices/pseudo/zfdnex@2/zfd@6:master6]):return = '2018-01-05T20:20:35.12961581Z control: initialized router for control server\n\0'[77]
265239856198224 7695b8af containerpilot[88608] lx-syscall::write:entry(1,/dev/zfd/1)
265239856252286 7695b8af logger[88600] syscall::read:return(3,/dev/zfd/3) = '2018-01-05T20:20:35.130251611Z control: listening to /var/run/containerpilot.socket\n\0'[84]
265239856254549 7695b8af containerpilot[88608] lx-syscall::write:return(1,/dev/zfd/1) = '2018-01-05T20:20:35.130251611Z control: listening to /var/run/containerpilot.socket\n\0'[84]
265239856263432 global zoneadmd[88429] read(16[/devices/pseudo/zfdnex@2/zfd@6:master6],1024):entry
265239856306813 global zoneadmd[88429] read(16[/devices/pseudo/zfdnex@2/zfd@6:master6]):return = '2018-01-05T20:20:35.130251611Z control: listening to /var/run/containerpilot.socket\n\0'[84]
265239856335381 7695b8af logger[88600] syscall::read:entry(3,/dev/zfd/3,4096)
265239856399669 7695b8af containerpilot[88608] lx-syscall::write:entry(1,/dev/zfd/1)
265239856445269 7695b8af containerpilot[88608] lx-syscall::write:return(1,/dev/zfd/1) = '2018-01-05T20:20:35.13045581Z event: {Startup global}\n\0'[54]
265239856447943 7695b8af logger[88600] syscall::read:return(3,/dev/zfd/3) = '2018-01-05T20:20:35.13045581Z event: {Startup global}\n\0'[54]
265239856455531 global zoneadmd[88429] read(16[/devices/pseudo/zfdnex@2/zfd@6:master6],1024):entry
265239856499825 global zoneadmd[88429] read(16[/devices/pseudo/zfdnex@2/zfd@6:master6]):return = '2018-01-05T20:20:35.13045581Z event: {Startup global}\n\0'[54]
265239856544429 7695b8af logger[88600] syscall::read:entry(3,/dev/zfd/3,4096)
265239857177870 7695b8af containerpilot[88608] lx-syscall::write:entry(1,/dev/zfd/1)
265239857230657 7695b8af containerpilot[88608] lx-syscall::write:return(1,/dev/zfd/1) = '2018-01-05T20:20:35.131232961Z logging.Run start\n\0'[49]
265239857230748 7695b8af logger[88600] syscall::read:return(3,/dev/zfd/3) = '2018-01-05T20:20:35.131232961Z logging.Run start\n\0'[49]
265239857241013 global zoneadmd[88429] read(16[/devices/pseudo/zfdnex@2/zfd@6:master6],1024):entry
265239857283568 global zoneadmd[88429] read(16[/devices/pseudo/zfdnex@2/zfd@6:master6]):return = '2018-01-05T20:20:35.131232961Z logging.Run start\n\0'[49]
Ok, this is going to get released ASAP.
Ref: #540
I believe this patch fixes the issues surrounding an incomplete community contribution. The problem is that the bytes returned from the buffer are never actually utilized (the buffer is only init'd as 0-byte and never used). Also, logging (
fmt.Print
) was being handled by the defunct writer type itself and not properly through Logrus as it was before the commit. I've removed the cruft and attempted to keep the formatting.I need to run tests and verify that this doesn't have any other residuals first but this will make a quick patch release for 3.6.2 by EOW.