Ticket #2265 (closed defect: fixed)

Opened 10 years ago

Last modified 10 years ago

kernel spams with useless messages (fbcon_event_notify action, etc.)

Reported by: lindi Owned by: openmoko-kernel
Priority: normal Milestone: stable-kernel-2009.1
Component: kernel Version: unspecified
Severity: normal Keywords:
Cc: Blocked By:
Blocking: Estimated Completion (week):
HasPatchForReview: yes PatchReviewResult: positive
Reproducible:

Description

Even when I am not using the phone at all my logs get filled with kernel messages like

Apr  7 04:18:32 ginger kernel: [  289.015000] fbcon_event_notify action=9, data=c4609e08
Apr  7 04:18:32 ginger kernel: [  289.015000] jbt6k74 spi2.0: **** jbt6k74 powerdown
Apr  7 04:18:42 ginger kernel: [  299.090000] fbcon_event_notify action=9, data=c4609e08
Apr  7 04:18:42 ginger kernel: [  299.090000] jbt6k74 spi2.0: **** jbt6k74 powerdown
Apr  7 04:18:52 ginger kernel: [  309.160000] fbcon_event_notify action=9, data=c4609e08
Apr  7 04:18:52 ginger kernel: [  309.160000] jbt6k74 spi2.0: **** jbt6k74 powerdown
Apr  7 04:19:02 ginger kernel: [  319.235000] fbcon_event_notify action=9, data=c4609e08
Apr  7 04:19:02 ginger kernel: [  319.235000] jbt6k74 spi2.0: **** jbt6k74 powerdown
Apr  7 04:19:12 ginger kernel: [  329.310000] fbcon_event_notify action=9, data=c4609e08
Apr  7 04:19:12 ginger kernel: [  329.310000] jbt6k74 spi2.0: **** jbt6k74 powerdown
Apr  7 04:19:13 ginger kernel: [  330.445000] pcf50633 0-0073: INT1=0x80 INT2=0x00 INT3=0x10 INT4=0x00 INT5=0x00
Apr  7 04:19:14 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: _readyToSend: watch timeout = None
Apr  7 04:19:14 ginger kernel: [  330.535000] pcf50633 0-0073: INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
Apr  7 04:19:14 ginger ogsmd    DEBUG    (<MiscChannel via /dev/pts/0>: last communication with modem was 50 seconds ago. Sending EOF to wakeup)
Apr  7 04:19:14 ginger kernel: [  330.555000] pcf50633 0-0073: INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
Apr  7 04:19:14 ginger kernel: [  330.715000] pcf50633 0-0073: INT1=0x00 INT2=0x00 INT3=0x20 INT4=0x00 INT5=0x00
Apr  7 04:19:14 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: sending 9 bytes: 'AT+COPS?\r'
Apr  7 04:19:14 ginger kernel: [  330.800000] pcf50633 0-0073: INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
Apr  7 04:19:14 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: _readyToRead: watch timeout = 317
Apr  7 04:19:14 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: got 28 bytes: '\r\n+COPS: 0,2,"24405"\r\n\r\nOK\r\n'
Apr  7 04:19:14 ginger kernel: [  330.845000] pcf50633 0-0073: INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
Apr  7 04:19:14 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: COMPLETED 'AT+COPS?' => ['+COPS: 0,2,"24405"', 'OK']
Apr  7 04:19:14 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: _readyToSend: watch timeout = None

this wastes disk space and makes finding the important stuff from logs more difficult. Please consider making these debug prints something that can be configured at runtime if they are really needed.

(Ignore the ogsmd DEBUG messages, they are caused by my periodic watchdog that checks that the phone is connected to GSM network every 50 seconds.)

I am reporting this bug against andy-tracking b8b36e5ec3db71d5 which is quite old. Please close this if the bug has already been fixed in newer kernels. I'll try to move to newer kernels when bugs #2255 and #2257 have been resolved.

Attachments

clean_unnecessary_log_bug_2265.patch (2.9 KB) - added by nicolas.dufresne 10 years ago.
Fix for ths issue (also sent to kernel mailing list)

Change History

comment:1 in reply to: ↑ description Changed 10 years ago by arhuaco

this wastes disk space and makes finding the important stuff from logs more difficult. Please consider making these debug prints something that can be configured at runtime if they are really needed.

I guess they are needed by kernel developers who can enable them anyway... Anyone against turning some of these messages off? They can be enabled at compile-time.

I'll try to move to newer kernels when bugs #2255 and #2257 have been resolved.

Good. At least you can count on #2255 being fixed soon.

comment:2 Changed 10 years ago by arhuaco

  • Milestone set to stable-kernel-2009.1

comment:3 Changed 10 years ago by nicolas.dufresne

JBT spam is already cleaned up. I'll fix fbcon.

Changed 10 years ago by nicolas.dufresne

Fix for ths issue (also sent to kernel mailing list)

comment:4 follow-up: ↓ 5 Changed 10 years ago by lindi

Thanks. After these the only regular kernel messages I see are

03:09:33 INT1=0x80 INT2=0x00 INT3=0x01 INT4=0x00 INT5=0x00
03:09:33 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
03:09:33 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
03:24:33 Charging restarted..
03:34:57 INT1=0x80 INT2=0x00 INT3=0x01 INT4=0x00 INT5=0x00
03:34:58 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
03:34:58 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
03:49:57 Charging restarted..
04:00:39 INT1=0x80 INT2=0x00 INT3=0x01 INT4=0x00 INT5=0x00
04:00:39 INT1=0x80 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
04:00:39 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
04:15:39 Charging restarted..
04:25:40 INT1=0x80 INT2=0x00 INT3=0x01 INT4=0x00 INT5=0x00
04:25:40 INT1=0x80 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
04:25:40 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
04:40:40 Charging restarted..
04:49:43 INT1=0x80 INT2=0x00 INT3=0x01 INT4=0x00 INT5=0x00
04:49:43 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
04:49:43 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
05:04:43 Charging restarted..
05:14:43 INT1=0x80 INT2=0x00 INT3=0x01 INT4=0x00 INT5=0x00
05:14:43 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
05:14:43 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
05:29:43 Charging restarted..
05:39:36 INT1=0x80 INT2=0x00 INT3=0x01 INT4=0x00 INT5=0x00
05:39:36 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
05:39:36 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
05:54:36 Charging restarted..
06:05:54 INT1=0x80 INT2=0x00 INT3=0x01 INT4=0x00 INT5=0x00
06:05:54 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
06:05:54 INT1=0x00 INT2=0x00 INT3=0x00 INT4=0x00 INT5=0x00
}}

We probably don't want to get rid of "Charging restarted.."  but what are these interrupts?

comment:5 in reply to: ↑ 4 Changed 10 years ago by arhuaco

  • Status changed from new to closed
  • PatchReviewResult set to positive
  • HasPatchForReview set
  • Resolution set to fixed

Patch applied.

We probably don't want to get rid of "Charging restarted.." but what are these interrupts?

lindi: I'll open another bug with the information you just sent so that we can receive feedback in case someone actually cares about the messages.

comment:6 Changed 10 years ago by arhuaco

Oh. Check #2237. Shall we really remove those "INT1=0x00 INT2=0x00"... messages? It seems in this case they were useful.

comment:7 Changed 10 years ago by nicolas.dufresne

Note I have kept most of those traces, I've just moved them to proper log level. If you set loglevel to 8, they will reapear. We could do the same for the power management traces. Still I think they are counter intuitive and may need some rework. As this chip is really central to our machine it would be worth to have some string table to translate the information into human readable containt ?

comment:8 Changed 10 years ago by lindi

Hard to say since I have not studied what interrupts those are.

Note: See TracTickets for help on using tickets.