syslog is corrupted

[marcusoverhagen]

Syslog doesn't properly log all dprintf messages.

initializing the /Haiku partition again didn't fix it.

examples:

(somwhere before the "KERN: em-alloc" a lot of messages are missing) KERN: con_init: trying module console/frame_buffer/v1 KERN: loaded driver /boot/beos/system/add-ons/kernel/drivers/dev/console KERN: loaded driver /boot/beos/system/add-ons/kernel/drivers/dev/dprintf KERN: loaded driver /boot/beos/system/add-ons/kernel/drivers/dev/keyboard KERN: loaded driver /boot/beos/system/add-ons/kernel/drivers/dev/null KERN: loaded driver /boot/beos/system/add-ons/kernel/drivers/dev/random KERN: loaded driver /boot/beos/system/add-ons/kernel/drivers/dev/tty KERN: loaded driver /boot/beos/system/add-ons/kernel/drivers/dev/zero KERN: loaded driver /boot/beos/systeloaded driver /boot/beos/system/add-ons/kernel/driveloaded driver /boot/beos/system/add-ons/kernel/drivers/dev/zeroloaded driver /boot/beos/system/add-ons/kernel/drivloaded driver /boot/beos/system/add-ons/kernel/driverloaded driver /boot/beos/system/add-ons/kernel/drivers/dev/zero KERN: em_alloc: size=8192, tag=0x00000000 KERN: Graphics Driver - mem_alloc: block_id=1, offset=0 KERN: Radeon - initRingBuffer: CP buffer address=1fffa000 KERN: Radeon - initRingBuffer: CP buffer size mask=10

or this one: KERN: ps2: ps2_dev_command cmd 0xf4, out 0, in 0, dev input/mouse/ps2/3 KERN: ps2: ps2_dev_command wait for ack res 0x00000000, wait-time 2446 KERN: ps2: ps2_dev_command got ACK KERN: ps2: ps2_dev_command result 0x00000000 KERN: ps2: mouse_open input/mouse/ps2/3 success KERN: ps2: mouse_open input/mouse/ps2KERN: ps2: KB_SET_KEY_REPEAT_RATE 300 KERN: ps2: set_typematic rate 300, delay 500000 KERN: ps2: ps2_dev_command cmd 0xf3, out 1, in 0, dev input/keyboard/at/0 KERN: ps2: ps2_dev_command out 0x20 KERN: ps2: ps2_dev_command wait for ack res 0x00000000, wait-time 6349

[Adek336]

syslog buffer too small

[Adek336]

In the attachment it is like

KERN: {QW<syslog_write call count>}{QE<dprint_args call count>, <free space in buff>} message

We see it discards a thousand messages because of a too small buffer and doesn't emit any <TRUNC>s or <DROP>s.

[Adek336]

- 74    #define SYSLOG_BUFFER_SIZE 65536
+ 74    #define SYSLOG_BUFFER_SIZE 131072

With 128 kb of buffer space, even with the additional message-number and free-space-in-buffer data stored in the buffer, the peak usage is around 100 kb. So by increasing the buffer space by 64 kb we ensure that the ~1000 messages previously dropped aren't anymore. Each of these messages is sent to the log because a programmer thought it was an important message, so loosing a thousand of them is very unfortunate and I think preserving them is worth the 64 kbs.

Perhaps SYSLOG_BUFFER_SIZE could be specified at build time in UserBuildConfig - so that if one day there is even more messages to be logged and they get dropped, one may fix the problem by tuning the build config; on the other hand, if the default buffer size was set to huge, somebody who wants to conserve memory can set it low.

        length = ring_buffer_readable(sSyslogBuffer);
        if (length > (int32)SYSLOG_MAX_MESSAGE_LENGTH)
             length = SYSLOG_MAX_MESSAGE_LENGTH;

        length = ring_buffer_read(sSyslogBuffer, 
            (uint8 *)sSyslogMessage->message, length);
  932   if (sSyslogDropped) {
  933   // add drop marker
- 934      if (length < (int32)SYSLOG_MAX_MESSAGE_LENGTH - 6)
- 935             strlcat(sSyslogMessage->message, "<DROP>", SYSLOG_MAX_MESSAGE_LENGTH);
- 936      else if (length > 7)
- 937           strcpy(sSyslogMessage->message + length - 7, "<DROP>");
+ 934      ring_buffer_write(sSyslogBuffer, (uint8 *) "<DROP>", 6);

        sSyslogDropped = false;
}

This fixes a problem with the <DROP> message being emitted in the wrong place. In the old code, if the buffer is full, sSyslogDropped is set and then, after sending approx MIN(SYSLOG_MAX_MESSAGE_LENGTH, SYSLOG_BUFFER_SIZE) the <DROP> message is emitted. SYSLOG_MAX_MESSAGE_LENGTH = approx 8192 so this is erroneus.

The proposed fix helps: <DROP> are emitted in the place, where a message has been indeed dropped.

[axeld]

I think that the syslog size could indeed be moved to build/config_headers, although it's probably simpler to just add a kernel setting for it.

The second patch makes definitely sense, thanks, I will apply it in a minute!

[axeld]

(In #2732) Thanks for the note :-)

[axeld]

I guess this one can be closed.