Opened 6 years ago

Closed 6 years ago

#205 closed defect (fixed)

Race condition in CallTrigger

Reported by: daniel Owned by: mickey
Priority: major Milestone: milestone5
Component: framework/oeventsd Version:
Keywords: Cc:

Description

When my Neo gets a call that is released right away the "state machine" in the rules gets confused and will ring anyway (forever or until a new call is received).
I guess this is because PlaySound? takes eons to actually complete...

2008.10.27 19:26:33 ogsmd    DEBUG    <UnsolicitedResponseChannel via /dev/pts/1>: got 44 bytes from: '\r\n%CPI: 1,0,0,0,1,0,"
01577xxxxxxx",129,,,0\r\n'
2008.10.27 19:26:33 ogsmd.objects INFO     org.freesmartphone.GSM.Call.CallStatus: 1 incoming {'status': 'incoming', 'peer': '
01577xxxxxxx', 'line': 0, 'direction': 'incoming'}
2008.10.27 19:26:33 oeventsd INFO     Receive CallStatus, status = incoming
2008.10.27 19:26:34 oeventsd INFO     RingToneAction play
2008.10.27 19:26:34 oeventsd INFO     call dbus signal /org/freesmartphone/Device/Display/pcf50633_bl SetBrightness((90,))
2008.10.27 19:26:34 oeventsd INFO     Receive CallStatus, status = incoming
2008.10.27 19:26:34 opreferencesd INFO     GetService phone
2008.10.27 19:26:35 ogsmd    DEBUG    <MiscChannel via /dev/pts/0>: got 17 bytes from: '\r\n+CRING: VOICE\r\n'
2008.10.27 19:26:36 ogsmd    INFO     <MiscChannel via /dev/pts/0>: unhandled unsolicited data incoming: '+CRING: VOICE'
2008.10.27 19:26:36 ogsmd    DEBUG    <UnsolicitedResponseChannel via /dev/pts/1>: got 210 bytes from: '\r\n%CPI: 1,0,0,1,1,0,
"01577xxxxxxx",129,,,0\r\n\r\n+CRING: VOICE\r\n\r\n+CLIP: "01577xxxxxxx",129,,,,0\r\n\r\n%CPI: 1,4,0,1,1,0,"01577xxxxxxx",129,
,,0\r\n\r\n%CPI: 1,1,0,1,1,0,"01577xxxxxxx",129,,16,0\r\n\r\n%CPI: 1,7,0,0,,,,,,,0\r\n'
2008.10.27 19:26:36 ogsmd.objects INFO     org.freesmartphone.GSM.Call.CallStatus: 1 incoming {'status': 'incoming', 'directio
n': 'incoming', 'peer': '01577xxxxxxx', 'line': 0}
2008.10.27 19:26:36 ogsmd.objects INFO     org.freesmartphone.GSM.Call.CallStatus: 1 release {'status': 'release'}
2008.10.27 19:26:36 ogsmd    DEBUG    <CallChannel via /dev/pts/2>: got 17 bytes from: '\r\n+CRING: VOICE\r\n'
2008.10.27 19:26:36 ogsmd    WARNING  CALLCHANNEL: UNHANDLED INTERMEDIATE: +CRING: VOICE
2008.10.27 19:26:36 odeviced.idlenotifier INFO     framework.subsystems.odeviced.idlenotifier state change to idle_dim
2008.10.27 19:26:36 odeviced.idlenotifier INFO     framework.subsystems.odeviced.idlenotifier state change to busy
2008.10.27 19:26:36 oeventsd INFO     Receive CallStatus, status = incoming
2008.10.27 19:26:36 oeventsd INFO     Receive CallStatus, status = incoming
2008.10.27 19:26:36 oeventsd INFO     Receive CallStatus, status = release
2008.10.27 19:26:36 oeventsd INFO     RingToneAction stop
2008.10.27 19:26:36 oeventsd INFO     Receive CallStatus, status = release
2008.10.27 19:26:36 oeventsd INFO     signal SetBrightness responded : ()
2008.10.27 19:26:36 oeventsd INFO     DebugAction : dbus trigger test
2008.10.27 19:26:36 oeventsd INFO     Receive IdleState, status = idle_dim
2008.10.27 19:26:36 oeventsd INFO     Receive IdleState, status = idle_dim
2008.10.27 19:26:36 oeventsd INFO     call dbus signal /org/freesmartphone/Device/Display/pcf50633_bl SetBrightness((20,))
2008.10.27 19:26:36 oeventsd INFO     Receive IdleState, status = idle_dim
2008.10.27 19:26:36 oeventsd INFO     DebugAction : dbus trigger test
2008.10.27 19:26:36 oeventsd INFO     Receive IdleState, status = busy
2008.10.27 19:26:36 oeventsd INFO     call dbus signal /org/freesmartphone/Device/Display/pcf50633_bl SetBrightness((90,))
2008.10.27 19:26:36 oeventsd INFO     Receive IdleState, status = busy
2008.10.27 19:26:36 oeventsd INFO     Receive IdleState, status = busy
2008.10.27 19:26:37 oeventsd INFO     signal SetBrightness responded : ()
2008.10.27 19:26:37 oeventsd INFO     signal SetBrightness responded : ()
2008.10.27 19:26:37 oeventsd INFO     Start ringing : tone=Arkanoid_PSID.sid, volume=10
2008.10.27 19:26:37 oeventsd INFO     call dbus signal /org/freesmartphone/Device/Audio PlaySound((u'/usr/share/sounds/Arkanoi
d_PSID.sid',))
2008.10.27 19:26:37 oeventsd INFO     call dbus signal /org/freesmartphone/Device/LED/neo1973_vibrator SetBlinking((300, 700))

Attachments (1)

race-condition (22.0 KB) - added by mickey 6 years ago.

Download all attachments as: .zip

Change History (6)

comment:1 Changed 6 years ago by daniel

  • Milestone changed from milestone4 to milestone5

This wont get fixed in ms4. Anyone who touches oeventsd so close to a release is bound to get burned. :-)

comment:2 Changed 6 years ago by mickey

Your analysis is correct, but I'm not sure whether I agree with your conclusion. The question is where to fix this, i.e.

  • whether odevice is supposed to 'remember' a stop command while the sound is not yet playing (e.g. while setting up the pipeline), or
  • whether the ring tone action in oeventsd is supposed to actually wait until the dbus command returns (which means the song has actually started playing or there was an error).

Opinions?

comment:3 Changed 6 years ago by daniel

  • Owner changed from charlie to mickey
  • Status changed from new to assigned

comment:4 Changed 6 years ago by arne.anka

not exactly sure, what "PlaySound?" is actually supposed to do -- but i do not use any sounds here, it just vibrates and in the case f the issue it continues to do so until i basically restart frameworkd.
so, if PlaySound? really does only concern _sounds_, then there's more to isue than just that.

Changed 6 years ago by mickey

comment:5 Changed 6 years ago by mickey

  • Resolution set to fixed
  • Status changed from assigned to closed

I have fixed this by

  • removing a dumb race in trigger/untrigger of the RingToneAction?.
  • serializing all dbus method calls triggered by actions.

Closing.

Note: See TracTickets for help on using tickets.