Work at SourceForge, help us to make it a better place! We have an immediate need for a Support Technician in our San Francisco or Denver office.

Close

#1082 sequencer crash on punch out from recording

closed
Chris Cannam
sequencer (64)
9
2012-09-16
2007-09-19
Chris Cannam
No

Bug reported by Emiliano Grilli:

  1. start recording MIDI (by pressing the record button on the transport window)

  2. play in some actual note events

  3. stop recording by hitting Space in the main window for punch-out

The sequencer then often crashes. No meaningful trace yet.

Also, when testing this I ended up with a great many overlapping segments of duration 3840, at time 0 on the recording track, containing nothing but a clef change. Sounds like a side-effect of the recent modification to add a default clef to recorded tracks.

Discussion

  • Chris Cannam
    Chris Cannam
    2007-09-19

    Logged In: YES
    user_id=13489
    Originator: YES

    Sequencer debug log and valgrind output:

    rosegarden (sequencer): client list changed
    rosegarden (sequencer): RosegardenSequencerApp::jumpTo(0, 0)
    rosegarden (sequencer): RosegardenSequencerApp::incrementTransportToken: incrementing to 2
    rosegarden (sequencer): RosegardenSequencerApp::record - recordMode is 5, transport status is 0
    rosegarden (sequencer): RosegardenSequencerApp::record() - starting to record
    rosegarden (sequencer): mmapping /var/tmp/kde-studio//rosegarden_metronome
    rosegarden (sequencer): MmappedSegment::map() : 0x4f24000,38404
    rosegarden (sequencer): mmapping /var/tmp/kde-studio//rosegarden_tempo
    rosegarden (sequencer): MmappedSegment::map() : 0x4531000,84
    rosegarden (sequencer): mmapping /var/tmp/kde-studio//rosegarden_timesig
    rosegarden (sequencer): MmappedSegment::map() : 0x4532000,4
    rosegarden (sequencer): RosegardenSequencerApp::play() - starting to play
    rosegarden (sequencer): [calling jumpToTime on start]
    rosegarden (sequencer): jumpToTime(0.000000000)
    SoundDriver::initialiseAudioQueue -- new queue has 0 files
    AudioPlayQueue::~AudioPlayQueue()
    rosegarden (sequencer): RosegardenSequencerApp::incrementTransportToken: incrementing to 3
    rosegarden (sequencer): Sequencer status changed from 0 to 2
    rosegarden (sequencer): Sequencer status changed from 2 to 1
    rosegarden (sequencer): RosegardenSequencerApp::remapSegment(/var/tmp/kde-studio//segment_8dbab60)
    ==3828==
    ==3828== Invalid read of size 4
    ==3828== at 0x819A451: Rosegarden::MmappedSegment::remap(unsigned) (MmappedSegment.cpp:125)
    ==3828== by 0x81A1D0C: Rosegarden::RosegardenSequencerApp::remapSegment(QString const&, unsigned) (RosegardenSequencerApp.cpp:952)
    ==3828== by 0x81B6477: Rosegarden::RosegardenSequencerIface::process(QCString const&, QMemArray<char> const&, QCString&, QMemArray<char>&) (RosegardenSequencerIface_skel.cpp:739)
    ==3828== by 0x4175DE3C: DCOPClient::receive(QCString const&, QCString const&, QCString const&, QMemArray<char> const&, QCString&, QMemArray<char>&) (in /usr/lib/libDCOP.so.4.2.0)
    ==3828== by 0x4175F57B: (within /usr/lib/libDCOP.so.4.2.0)
    ==3828== by 0x4175FCB0: (within /usr/lib/libDCOP.so.4.2.0)
    ==3828== by 0x4176FA51: KDE_IceProcessMessages (in /usr/lib/libDCOP.so.4.2.0)
    ==3828== by 0x417562D8: DCOPClient::processSocketData(int) (in /usr/lib/libDCOP.so.4.2.0)
    ==3828== by 0x4175F8A8: DCOPClient::qt_invoke(int, QUObject) (in /usr/lib/libDCOP.so.4.2.0)
    ==3828== by 0x41CB12EE: QObject::activate_signal(QConnectionList
    , QUObject*) (in /usr/lib/libqt-mt.so.3.3.7)
    ==3828== by 0x41CB1BF5: QObject::activate_signal(int, int) (in /usr/lib/libqt-mt.so.3.3.7)
    ==3828== by 0x4203B21A: QSocketNotifier::activated(int) (in /usr/lib/libqt-mt.so.3.3.7)
    ==3828== Address 0x4 is not stack'd, malloc'd or (recently) free'd
    KCrash: Application 'rosegardensequencer' crashing...

     
  • Chris Cannam
    Chris Cannam
    2007-09-19

    Logged In: YES
    user_id=13489
    Originator: YES

    It's the "this" pointer that's invalid -- i.e. the MmappedSegment object itself. The lookup in m_mmappedSegments at RosegardenSequencerApp.cpp:951 is returning an invalid pointer.

     
  • Chris Cannam
    Chris Cannam
    2007-09-19

    Logged In: YES
    user_id=13489
    Originator: YES

    Here's the staggering amount of debug output from the GUI between starting to record (using punch in, this time, but the result was the same) and stopping (using punch out, followed by sequencer crash). It seems to be doing something lots and lots of times. This is also the point at which all the empty segments are created (they have the same start time as the recorded segment that was created on punch-in).

    rosegarden (sequence manager): SequenceManager::record(true)
    rosegarden (sequence manager): SequenceManager::record - punch in recording
    rosegarden (sequence manager): Sound driver status is: 6
    rosegarden (sequence manager): ControlBlockMmapper::updateMetronomeForRecord: muted=false
    rosegarden (sequence manager): SequenceManager: mdoc->addRecordMIDISegment(0)
    rosegarden: RosegardenGUIDoc::addRecordMIDISegment(0)
    rosegarden (sequence manager): SequenceManager::segmentAdded(0x8f66210)
    rosegarden: CompositionModelImpl::addRecordingItem: now have 1 recording items
    rosegarden (sequence manager): SequenceManager::record() - starting to record
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden: RosegardenGUIDoc::insertRecordedEvent() - matches filter
    rosegarden (sequence manager): SequenceManager::record(true)
    rosegarden (sequence manager): SequenceManager::record - stop recording and keep playing
    rosegarden: RosegardenGUIDoc::stopRecordingMidi
    rosegarden: RosegardenGUIDoc::stopRecordingMidi: have something
    rosegarden: MultiViewCommandHistory::addCommand: Insert Recorded MIDI
    rosegarden: BasicCommand(Heuristic Notation &Quantize)::copyTo: 0x8f66210 to 0x8f695f4, range (7701,10548)
    NotationQuantizer::Impl::quantizeRange: from time 7701 to -1
    NotationQuantizer: 60 events (59 notes), 6 passes, 60 good sets, 0 bad sets, 10ms elapsed
    Profiles::dump() :
    -> StudioControl::sendQuarterNoteLength: CPU: 1 calls, 10ms, 10000us/call
    -> StudioControl::sendQuarterNoteLength: real: 1 calls, 0.000245000R, 0.000245000R/call
    -> StudioControl::sendQuarterNoteLength: last: CPU: 10ms, real: 0.000245000R
    -> StudioControl::sendMappedComposition: CPU: 21 calls, 0ms, 0us/call
    -> StudioControl::sendMappedComposition: real: 21 calls, 0.010152000R, 0.000483429R/call
    -> StudioControl::sendMappedComposition: last: CPU: 0ms, real: 0.000028000R
    -> StudioControl::sendMappedEvent: CPU: 20 calls, 0ms, 0us/call
    -> StudioControl::sendMappedEvent: real: 20 calls, 0.010457000R, 0.000522850R/call
    -> StudioControl::sendMappedEvent: last: CPU: 0ms, real: 0.000065000R
    -> StudioControl::createStudioObject: CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::createStudioObject: real: 6 calls, 0.036230000R, 0.006038333R/call
    -> StudioControl::createStudioObject: last: CPU: 0ms, real: 0.008548000R
    -> StudioControl::setStudioObjectProperty(float): CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperty(float): real: 6 calls, 0.000402000R, 0.000067000R/call
    -> StudioControl::setStudioObjectProperty(float): last: CPU: 0ms, real: 0.000036000R
    -> StudioControl::setStudioObjectProperties(floats): CPU: 2 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperties(floats): real: 2 calls, 0.000133000R, 0.000066500R/call
    -> StudioControl::setStudioObjectProperties(floats): last: CPU: 0ms, real: 0.000034000R
    -> RosegardenGUIDoc::syncDevices: CPU: 4 calls, 210ms, 52500us/call
    -> RosegardenGUIDoc::syncDevices: real: 4 calls, 0.435456000R, 0.108864000R/call
    -> RosegardenGUIDoc::syncDevices: last: CPU: 0ms, real: 0.077598000R
    -> initialiseStudio: CPU: 2 calls, 150ms, 75000us/call
    -> initialiseStudio: real: 2 calls, 0.383968000R, 0.191984000R/call
    -> initialiseStudio: last: CPU: 0ms, real: 0.045135000R
    -> EventQuantizeCommand::modifySegment: CPU: 1 calls, 20ms, 20000us/call
    -> EventQuantizeCommand::modifySegment: real: 1 calls, 0.036136000R, 0.036136000R/call
    -> EventQuantizeCommand::modifySegment: last: CPU: 20ms, real: 0.036136000R
    -> NotationQuantizer::Impl::quantizeDuration: CPU: 36 calls, 10ms, 277.778us/call
    -> NotationQuantizer::Impl::quantizeDuration: real: 36 calls, 0.002624000R, 0.000072889R/call
    -> NotationQuantizer::Impl::quantizeDuration: last: CPU: 0ms, real: 0.000017000R
    -> NotationQuantizer::Impl::quantizeDurationProvisional: CPU: 110 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: real: 110 calls, 0.001052000R, 0.000009564R/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: last: CPU: 0ms, real: 0.000009000R
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: CPU: 551 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: real: 551 calls, 0.001581000R, 0.000002869R/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: last: CPU: 0ms, real: 0.000002000R
    -> NotationQuantizer::Impl::isValidTupletAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::isValidTupletAt: real: 10 calls, 0.000063000R, 0.000006300R/call
    -> NotationQuantizer::Impl::isValidTupletAt: last: CPU: 0ms, real: 0.000005000R
    -> NotationQuantizer::Impl::scanTupletsAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsAt: real: 10 calls, 0.000227000R, 0.000022700R/call
    -> NotationQuantizer::Impl::scanTupletsAt: last: CPU: 0ms, real: 0.000016000R
    -> NotationQuantizer::Impl::scanTupletsInBar: CPU: 2 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsInBar: real: 2 calls, 0.000296000R, 0.000148000R/call
    -> NotationQuantizer::Impl::scanTupletsInBar: last: CPU: 0ms, real: 0.000167000R
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: CPU: 110 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: real: 110 calls, 0.004917000R, 0.000044700R/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: last: CPU: 0ms, real: 0.000044000R
    -> NotationQuantizer::Impl::quantizeRange: CPU: 2 calls, 20ms, 10000us/call
    -> NotationQuantizer::Impl::quantizeRange: real: 2 calls, 0.023657000R, 0.011828500R/call
    -> NotationQuantizer::Impl::quantizeRange: last: CPU: 10ms, real: 0.012054000R
    -> Quantizer::setToTarget: CPU: 110 calls, 10ms, 90.9091us/call
    -> Quantizer::setToTarget: real: 110 calls, 0.008195000R, 0.000074500R/call
    -> Quantizer::setToTarget: last: CPU: 0ms, real: 0.000059000R
    -> Quantizer::getFromSource: CPU: 375 calls, 0ms, 0us/call
    -> Quantizer::getFromSource: real: 375 calls, 0.000459000R, 0.000001224R/call
    -> Quantizer::getFromSource: last: CPU: 0ms, real: 0.000001000R
    -> Segment::normalizeRests: CPU: 3 calls, 0ms, 0us/call
    -> Segment::normalizeRests: real: 3 calls, 0.005898000R, 0.001966000R/call
    -> Segment::normalizeRests: last: CPU: 0ms, real: 0.001337000R
    Profiles::dump() finished
    rosegarden: RosegardenGUIDoc::addRecordMIDISegment(0)
    rosegarden (sequence manager): SequenceManager::segmentAdded(0x8f28ef8)
    rosegarden: CompositionModelImpl::addRecordingItem: now have 2 recording items
    Profiler : id = EventQuantizeCommand::modifySegment - elapsed = 20ms CPU, 0.081320000R real
    rosegarden: BasicCommand(Heuristic Notation &Quantize): updated refresh statuses 7701 -> 10548
    rosegarden: BasicCommand(&Normalize Rests)::copyTo: 0x8f66210 to 0x8f291cc, range (7680,11520)
    rosegarden: BasicCommand(&Normalize Rests): updated refresh statuses 7680 -> 11520
    rosegarden: SegmentParameterBox::update()
    rosegarden (sequence manager): SequenceManager::update()
    rosegarden: RosegardenGUIDoc::slotDocumentModified()
    rosegarden: RosegardenGUIDoc[0x8dcbb60]::setModified(true)
    rosegarden: RosegardenGUIApp::slotDocumentModified(true) - doc path =
    rosegarden: MultiViewCommandHistory::addCommand: Insert Recorded MIDI
    rosegarden: BasicCommand(Heuristic Notation &Quantize)::copyTo: 0x8f28ef8 to 0x8f5be64, range (7701,7702)
    NotationQuantizer::Impl::quantizeRange: from time 7701 to -1
    NotationQuantizer: 1 events (0 notes), 6 passes, 1 good sets, 0 bad sets, 0ms elapsed
    Profiles::dump() :
    -> StudioControl::sendQuarterNoteLength: CPU: 1 calls, 10ms, 10000us/call
    -> StudioControl::sendQuarterNoteLength: real: 1 calls, 0.000245000R, 0.000245000R/call
    -> StudioControl::sendQuarterNoteLength: last: CPU: 10ms, real: 0.000245000R
    -> StudioControl::sendMappedComposition: CPU: 21 calls, 0ms, 0us/call
    -> StudioControl::sendMappedComposition: real: 21 calls, 0.010152000R, 0.000483429R/call
    -> StudioControl::sendMappedComposition: last: CPU: 0ms, real: 0.000028000R
    -> StudioControl::sendMappedEvent: CPU: 20 calls, 0ms, 0us/call
    -> StudioControl::sendMappedEvent: real: 20 calls, 0.010457000R, 0.000522850R/call
    -> StudioControl::sendMappedEvent: last: CPU: 0ms, real: 0.000065000R
    -> StudioControl::createStudioObject: CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::createStudioObject: real: 6 calls, 0.036230000R, 0.006038333R/call
    -> StudioControl::createStudioObject: last: CPU: 0ms, real: 0.008548000R
    -> StudioControl::setStudioObjectProperty(float): CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperty(float): real: 6 calls, 0.000402000R, 0.000067000R/call
    -> StudioControl::setStudioObjectProperty(float): last: CPU: 0ms, real: 0.000036000R
    -> StudioControl::setStudioObjectProperties(floats): CPU: 2 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperties(floats): real: 2 calls, 0.000133000R, 0.000066500R/call
    -> StudioControl::setStudioObjectProperties(floats): last: CPU: 0ms, real: 0.000034000R
    -> RosegardenGUIDoc::syncDevices: CPU: 4 calls, 210ms, 52500us/call
    -> RosegardenGUIDoc::syncDevices: real: 4 calls, 0.435456000R, 0.108864000R/call
    -> RosegardenGUIDoc::syncDevices: last: CPU: 0ms, real: 0.077598000R
    -> initialiseStudio: CPU: 2 calls, 150ms, 75000us/call
    -> initialiseStudio: real: 2 calls, 0.383968000R, 0.191984000R/call
    -> initialiseStudio: last: CPU: 0ms, real: 0.045135000R
    -> EventQuantizeCommand::modifySegment: CPU: 2 calls, 40ms, 20000us/call
    -> EventQuantizeCommand::modifySegment: real: 2 calls, 0.117456000R, 0.058728000R/call
    -> EventQuantizeCommand::modifySegment: last: CPU: 20ms, real: 0.081320000R
    -> NotationQuantizer::Impl::quantizeDuration: CPU: 36 calls, 10ms, 277.778us/call
    -> NotationQuantizer::Impl::quantizeDuration: real: 36 calls, 0.002624000R, 0.000072889R/call
    -> NotationQuantizer::Impl::quantizeDuration: last: CPU: 0ms, real: 0.000017000R
    -> NotationQuantizer::Impl::quantizeDurationProvisional: CPU: 111 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: real: 111 calls, 0.001065000R, 0.000009595R/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: last: CPU: 0ms, real: 0.000013000R
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: CPU: 556 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: real: 556 calls, 0.001592000R, 0.000002863R/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: last: CPU: 0ms, real: 0.000002000R
    -> NotationQuantizer::Impl::isValidTupletAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::isValidTupletAt: real: 10 calls, 0.000063000R, 0.000006300R/call
    -> NotationQuantizer::Impl::isValidTupletAt: last: CPU: 0ms, real: 0.000005000R
    -> NotationQuantizer::Impl::scanTupletsAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsAt: real: 10 calls, 0.000227000R, 0.000022700R/call
    -> NotationQuantizer::Impl::scanTupletsAt: last: CPU: 0ms, real: 0.000016000R
    -> NotationQuantizer::Impl::scanTupletsInBar: CPU: 3 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsInBar: real: 3 calls, 0.000298000R, 0.000099333R/call
    -> NotationQuantizer::Impl::scanTupletsInBar: last: CPU: 0ms, real: 0.000002000R
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: CPU: 111 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: real: 111 calls, 0.004963000R, 0.000044712R/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: last: CPU: 0ms, real: 0.000046000R
    -> NotationQuantizer::Impl::quantizeRange: CPU: 3 calls, 20ms, 6666.67us/call
    -> NotationQuantizer::Impl::quantizeRange: real: 3 calls, 0.024804000R, 0.008268000R/call
    -> NotationQuantizer::Impl::quantizeRange: last: CPU: 0ms, real: 0.001147000R
    -> Quantizer::setToTarget: CPU: 111 calls, 10ms, 90.0901us/call
    -> Quantizer::setToTarget: real: 111 calls, 0.008274000R, 0.000074541R/call
    -> Quantizer::setToTarget: last: CPU: 0ms, real: 0.000079000R
    -> Quantizer::getFromSource: CPU: 377 calls, 0ms, 0us/call
    -> Quantizer::getFromSource: real: 377 calls, 0.000462000R, 0.000001225R/call
    -> Quantizer::getFromSource: last: CPU: 0ms, real: 0.000002000R
    -> Segment::normalizeRests: CPU: 6 calls, 0ms, 0us/call
    -> Segment::normalizeRests: real: 6 calls, 0.011546000R, 0.001924333R/call
    -> Segment::normalizeRests: last: CPU: 0ms, real: 0.001896000R
    Profiles::dump() finished
    rosegarden: TrackEditor::paintEvent: composition is modified, update everything
    rosegarden: CompositionModelImpl::clearPreviewCache
    rosegarden (sequence manager): SequenceManager::event() with user event
    rosegarden (sequence manager): SequenceManager::event(): update requested
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus()
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: segments modified by changes to trigger segments are:
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: we have 1 segments
    rosegarden (sequence manager): SequenceManager::segmentModified(0x8f51870)
    rosegarden (sequence manager): CompositionMmapper::segmentModified(0x8f51870) - mmapper = 0x8f651a0
    rosegarden (sequence manager): SegmentMmapper::refresh() - /var/tmp/kde-studio//segment_8f51870 - m_mmappedRegion = 0xb7210000 - m_mmappedEventBuffer = 0xb7210004 - new size = 5124 - old size = 5124
    rosegarden (sequence manager): SequenceManager::segmentModified() : size changed = false
    rosegarden (sequence manager): SequenceManager::processAddedSegment(0x8f66210)
    rosegarden (sequence manager): CompositionMmapper::segmentAdded(0x8f66210)
    rosegarden (sequence manager): CompositionMmapper::mmapSegment(0x8f66210)
    rosegarden (sequence manager): SegmentMmapper : 0x8f74ca0 trying to mmap /var/tmp/kde-studio//segment_8f66210
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f66210 to 6324 - current size = 6324
    rosegarden (sequence manager): SegmentMmapper::doMmap() - mmap size : 6324 at 0xb720e000
    rosegarden (sequence manager): SegmentMmapper::init : mmap size = 6324 for segment Acoustic Grand Piano (recorded)
    rosegarden (sequence manager): SequenceManager::processAddedSegment(0x8f28ef8)
    rosegarden (sequence manager): CompositionMmapper::segmentAdded(0x8f28ef8)
    rosegarden (sequence manager): CompositionMmapper::mmapSegment(0x8f28ef8)
    rosegarden (sequence manager): SegmentMmapper : 0x8f28d68 trying to mmap /var/tmp/kde-studio//segment_8f28ef8
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f28ef8 to 84 - current size = 84
    rosegarden (sequence manager): SegmentMmapper::doMmap() - mmap size : 84 at 0xb720d000
    rosegarden (sequence manager): SegmentMmapper::init : mmap size = 84 for segment Acoustic Grand Piano (recorded)
    rosegarden: RosegardenGUIDoc::addRecordMIDISegment(0)
    rosegarden (sequence manager): SequenceManager::segmentAdded(0x8f5c2a0)
    rosegarden: CompositionModelImpl::addRecordingItem: now have 3 recording items
    Profiler : id = EventQuantizeCommand::modifySegment - elapsed = 20ms CPU, 0.095356000R real
    rosegarden: BasicCommand(Heuristic Notation &Quantize): updated refresh statuses 7701 -> 7702
    rosegarden: BasicCommand(&Normalize Rests)::copyTo: 0x8f28ef8 to 0x8f7608c, range (7680,11520)
    rosegarden: BasicCommand(&Normalize Rests): updated refresh statuses 7680 -> 11520
    rosegarden: SegmentParameterBox::update()
    rosegarden (sequence manager): SequenceManager::update()
    rosegarden: RosegardenGUIDoc::slotDocumentModified()
    rosegarden: RosegardenGUIDoc[0x8dcbb60]::setModified(true)
    rosegarden: RosegardenGUIApp::slotDocumentModified(true) - doc path =
    rosegarden: MultiViewCommandHistory::addCommand: Insert Recorded MIDI
    rosegarden: BasicCommand(Heuristic Notation &Quantize)::copyTo: 0x8f5c2a0 to 0x8f5c72c, range (7701,7702)
    NotationQuantizer::Impl::quantizeRange: from time 7701 to -1
    NotationQuantizer: 1 events (0 notes), 6 passes, 1 good sets, 0 bad sets, 0ms elapsed
    Profiles::dump() :
    -> StudioControl::sendQuarterNoteLength: CPU: 1 calls, 10ms, 10000us/call
    -> StudioControl::sendQuarterNoteLength: real: 1 calls, 0.000245000R, 0.000245000R/call
    -> StudioControl::sendQuarterNoteLength: last: CPU: 10ms, real: 0.000245000R
    -> StudioControl::sendMappedComposition: CPU: 21 calls, 0ms, 0us/call
    -> StudioControl::sendMappedComposition: real: 21 calls, 0.010152000R, 0.000483429R/call
    -> StudioControl::sendMappedComposition: last: CPU: 0ms, real: 0.000028000R
    -> StudioControl::sendMappedEvent: CPU: 20 calls, 0ms, 0us/call
    -> StudioControl::sendMappedEvent: real: 20 calls, 0.010457000R, 0.000522850R/call
    -> StudioControl::sendMappedEvent: last: CPU: 0ms, real: 0.000065000R
    -> StudioControl::createStudioObject: CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::createStudioObject: real: 6 calls, 0.036230000R, 0.006038333R/call
    -> StudioControl::createStudioObject: last: CPU: 0ms, real: 0.008548000R
    -> StudioControl::setStudioObjectProperty(float): CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperty(float): real: 6 calls, 0.000402000R, 0.000067000R/call
    -> StudioControl::setStudioObjectProperty(float): last: CPU: 0ms, real: 0.000036000R
    -> StudioControl::setStudioObjectProperties(floats): CPU: 2 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperties(floats): real: 2 calls, 0.000133000R, 0.000066500R/call
    -> StudioControl::setStudioObjectProperties(floats): last: CPU: 0ms, real: 0.000034000R
    -> RosegardenGUIDoc::syncDevices: CPU: 4 calls, 210ms, 52500us/call
    -> RosegardenGUIDoc::syncDevices: real: 4 calls, 0.435456000R, 0.108864000R/call
    -> RosegardenGUIDoc::syncDevices: last: CPU: 0ms, real: 0.077598000R
    -> initialiseStudio: CPU: 2 calls, 150ms, 75000us/call
    -> initialiseStudio: real: 2 calls, 0.383968000R, 0.191984000R/call
    -> initialiseStudio: last: CPU: 0ms, real: 0.045135000R
    -> EventQuantizeCommand::modifySegment: CPU: 3 calls, 60ms, 20000us/call
    -> EventQuantizeCommand::modifySegment: real: 3 calls, 0.212812000R, 0.070937333R/call
    -> EventQuantizeCommand::modifySegment: last: CPU: 20ms, real: 0.095356000R
    -> NotationQuantizer::Impl::quantizeDuration: CPU: 36 calls, 10ms, 277.778us/call
    -> NotationQuantizer::Impl::quantizeDuration: real: 36 calls, 0.002624000R, 0.000072889R/call
    -> NotationQuantizer::Impl::quantizeDuration: last: CPU: 0ms, real: 0.000017000R
    -> NotationQuantizer::Impl::quantizeDurationProvisional: CPU: 112 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: real: 112 calls, 0.001078000R, 0.000009625R/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: last: CPU: 0ms, real: 0.000013000R
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: CPU: 561 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: real: 561 calls, 0.001601000R, 0.000002854R/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: last: CPU: 0ms, real: 0.000002000R
    -> NotationQuantizer::Impl::isValidTupletAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::isValidTupletAt: real: 10 calls, 0.000063000R, 0.000006300R/call
    -> NotationQuantizer::Impl::isValidTupletAt: last: CPU: 0ms, real: 0.000005000R
    -> NotationQuantizer::Impl::scanTupletsAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsAt: real: 10 calls, 0.000227000R, 0.000022700R/call
    -> NotationQuantizer::Impl::scanTupletsAt: last: CPU: 0ms, real: 0.000016000R
    -> NotationQuantizer::Impl::scanTupletsInBar: CPU: 4 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsInBar: real: 4 calls, 0.000301000R, 0.000075250R/call
    -> NotationQuantizer::Impl::scanTupletsInBar: last: CPU: 0ms, real: 0.000003000R
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: CPU: 112 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: real: 112 calls, 0.005008000R, 0.000044714R/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: last: CPU: 0ms, real: 0.000045000R
    -> NotationQuantizer::Impl::quantizeRange: CPU: 4 calls, 20ms, 5000us/call
    -> NotationQuantizer::Impl::quantizeRange: real: 4 calls, 0.025056000R, 0.006264000R/call
    -> NotationQuantizer::Impl::quantizeRange: last: CPU: 0ms, real: 0.000252000R
    -> Quantizer::setToTarget: CPU: 112 calls, 10ms, 89.2857us/call
    -> Quantizer::setToTarget: real: 112 calls, 0.008348000R, 0.000074536R/call
    -> Quantizer::setToTarget: last: CPU: 0ms, real: 0.000074000R
    -> Quantizer::getFromSource: CPU: 379 calls, 0ms, 0us/call
    -> Quantizer::getFromSource: real: 379 calls, 0.000465000R, 0.000001227R/call
    -> Quantizer::getFromSource: last: CPU: 0ms, real: 0.000001000R
    -> Segment::normalizeRests: CPU: 9 calls, 0ms, 0us/call
    -> Segment::normalizeRests: real: 9 calls, 0.011697000R, 0.001299667R/call
    -> Segment::normalizeRests: last: CPU: 0ms, real: 0.000120000R
    Profiles::dump() finished
    rosegarden: TrackEditor::paintEvent: composition is modified, update everything
    rosegarden: CompositionModelImpl::clearPreviewCache
    rosegarden (sequence manager): SequenceManager::event() with user event
    rosegarden (sequence manager): SequenceManager::event(): update requested
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus()
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: segments modified by changes to trigger segments are:
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: we have 3 segments
    rosegarden (sequence manager): SequenceManager::segmentModified(0x8f28ef8)
    rosegarden (sequence manager): CompositionMmapper::segmentModified(0x8f28ef8) - mmapper = 0x8f28d68
    rosegarden (sequence manager): SegmentMmapper::refresh() - /var/tmp/kde-studio//segment_8f28ef8 - m_mmappedRegion = 0xb720d000 - m_mmappedEventBuffer = 0xb720d004 - new size = 164 - old size = 84
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f28ef8 to 164 - current size = 84
    rosegarden (sequence manager): SegmentMmapper : remapping /var/tmp/kde-studio//segment_8f28ef8 from size 84 to size 164
    rosegarden (sequence manager): SequenceManager::segmentModified() : size changed = true
    rosegarden (sequence manager): SequenceManager::segmentModified(0x8f66210)
    rosegarden (sequence manager): CompositionMmapper::segmentModified(0x8f66210) - mmapper = 0x8f74ca0
    rosegarden (sequence manager): SegmentMmapper::refresh() - /var/tmp/kde-studio//segment_8f66210 - m_mmappedRegion = 0xb720e000 - m_mmappedEventBuffer = 0xb720e004 - new size = 6324 - old size = 6324
    rosegarden (sequence manager): SequenceManager::segmentModified() : size changed = false
    rosegarden (sequence manager): SequenceManager::processAddedSegment(0x8f5c2a0)
    rosegarden (sequence manager): CompositionMmapper::segmentAdded(0x8f5c2a0)
    rosegarden (sequence manager): CompositionMmapper::mmapSegment(0x8f5c2a0)
    rosegarden (sequence manager): SegmentMmapper : 0x8f75a68 trying to mmap /var/tmp/kde-studio//segment_8f5c2a0
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f5c2a0 to 84 - current size = 84
    rosegarden (sequence manager): SegmentMmapper::doMmap() - mmap size : 84 at 0xb720c000
    rosegarden (sequence manager): SegmentMmapper::init : mmap size = 84 for segment Acoustic Grand Piano (recorded)
    rosegarden: RosegardenGUIDoc::addRecordMIDISegment(0)
    rosegarden (sequence manager): SequenceManager::segmentAdded(0x8f77588)
    rosegarden: CompositionModelImpl::addRecordingItem: now have 4 recording items
    Profiler : id = EventQuantizeCommand::modifySegment - elapsed = 30ms CPU, 0.049552000R real
    rosegarden: BasicCommand(Heuristic Notation &Quantize): updated refresh statuses 7701 -> 7702
    rosegarden: BasicCommand(&Normalize Rests)::copyTo: 0x8f5c2a0 to 0x8f5c4fc, range (7680,11520)
    rosegarden: BasicCommand(&Normalize Rests): updated refresh statuses 7680 -> 11520
    rosegarden: SegmentParameterBox::update()
    rosegarden (sequence manager): SequenceManager::update()
    rosegarden: RosegardenGUIDoc::slotDocumentModified()
    rosegarden: RosegardenGUIDoc[0x8dcbb60]::setModified(true)
    rosegarden: RosegardenGUIApp::slotDocumentModified(true) - doc path =
    rosegarden: MultiViewCommandHistory::addCommand: Insert Recorded MIDI
    rosegarden: BasicCommand(Heuristic Notation &Quantize)::copyTo: 0x8f77588 to 0x8f77394, range (7701,7702)
    NotationQuantizer::Impl::quantizeRange: from time 7701 to -1
    NotationQuantizer: 1 events (0 notes), 6 passes, 1 good sets, 0 bad sets, 0ms elapsed
    Profiles::dump() :
    -> StudioControl::sendQuarterNoteLength: CPU: 1 calls, 10ms, 10000us/call
    -> StudioControl::sendQuarterNoteLength: real: 1 calls, 0.000245000R, 0.000245000R/call
    -> StudioControl::sendQuarterNoteLength: last: CPU: 10ms, real: 0.000245000R
    -> StudioControl::sendMappedComposition: CPU: 21 calls, 0ms, 0us/call
    -> StudioControl::sendMappedComposition: real: 21 calls, 0.010152000R, 0.000483429R/call
    -> StudioControl::sendMappedComposition: last: CPU: 0ms, real: 0.000028000R
    -> StudioControl::sendMappedEvent: CPU: 20 calls, 0ms, 0us/call
    -> StudioControl::sendMappedEvent: real: 20 calls, 0.010457000R, 0.000522850R/call
    -> StudioControl::sendMappedEvent: last: CPU: 0ms, real: 0.000065000R
    -> StudioControl::createStudioObject: CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::createStudioObject: real: 6 calls, 0.036230000R, 0.006038333R/call
    -> StudioControl::createStudioObject: last: CPU: 0ms, real: 0.008548000R
    -> StudioControl::setStudioObjectProperty(float): CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperty(float): real: 6 calls, 0.000402000R, 0.000067000R/call
    -> StudioControl::setStudioObjectProperty(float): last: CPU: 0ms, real: 0.000036000R
    -> StudioControl::setStudioObjectProperties(floats): CPU: 2 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperties(floats): real: 2 calls, 0.000133000R, 0.000066500R/call
    -> StudioControl::setStudioObjectProperties(floats): last: CPU: 0ms, real: 0.000034000R
    -> RosegardenGUIDoc::syncDevices: CPU: 4 calls, 210ms, 52500us/call
    -> RosegardenGUIDoc::syncDevices: real: 4 calls, 0.435456000R, 0.108864000R/call
    -> RosegardenGUIDoc::syncDevices: last: CPU: 0ms, real: 0.077598000R
    -> initialiseStudio: CPU: 2 calls, 150ms, 75000us/call
    -> initialiseStudio: real: 2 calls, 0.383968000R, 0.191984000R/call
    -> initialiseStudio: last: CPU: 0ms, real: 0.045135000R
    -> EventQuantizeCommand::modifySegment: CPU: 4 calls, 90ms, 22500us/call
    -> EventQuantizeCommand::modifySegment: real: 4 calls, 0.262364000R, 0.065591000R/call
    -> EventQuantizeCommand::modifySegment: last: CPU: 30ms, real: 0.049552000R
    -> NotationQuantizer::Impl::quantizeDuration: CPU: 36 calls, 10ms, 277.778us/call
    -> NotationQuantizer::Impl::quantizeDuration: real: 36 calls, 0.002624000R, 0.000072889R/call
    -> NotationQuantizer::Impl::quantizeDuration: last: CPU: 0ms, real: 0.000017000R
    -> NotationQuantizer::Impl::quantizeDurationProvisional: CPU: 113 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: real: 113 calls, 0.001091000R, 0.000009655R/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: last: CPU: 0ms, real: 0.000013000R
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: CPU: 566 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: real: 566 calls, 0.001610000R, 0.000002845R/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: last: CPU: 0ms, real: 0.000001000R
    -> NotationQuantizer::Impl::isValidTupletAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::isValidTupletAt: real: 10 calls, 0.000063000R, 0.000006300R/call
    -> NotationQuantizer::Impl::isValidTupletAt: last: CPU: 0ms, real: 0.000005000R
    -> NotationQuantizer::Impl::scanTupletsAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsAt: real: 10 calls, 0.000227000R, 0.000022700R/call
    -> NotationQuantizer::Impl::scanTupletsAt: last: CPU: 0ms, real: 0.000016000R
    -> NotationQuantizer::Impl::scanTupletsInBar: CPU: 5 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsInBar: real: 5 calls, 0.000303000R, 0.000060600R/call
    -> NotationQuantizer::Impl::scanTupletsInBar: last: CPU: 0ms, real: 0.000002000R
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: CPU: 113 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: real: 113 calls, 0.005053000R, 0.000044717R/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: last: CPU: 0ms, real: 0.000045000R
    -> NotationQuantizer::Impl::quantizeRange: CPU: 5 calls, 20ms, 4000us/call
    -> NotationQuantizer::Impl::quantizeRange: real: 5 calls, 0.025290000R, 0.005058000R/call
    -> NotationQuantizer::Impl::quantizeRange: last: CPU: 0ms, real: 0.000234000R
    -> Quantizer::setToTarget: CPU: 113 calls, 10ms, 88.4956us/call
    -> Quantizer::setToTarget: real: 113 calls, 0.008421000R, 0.000074522R/call
    -> Quantizer::setToTarget: last: CPU: 0ms, real: 0.000073000R
    -> Quantizer::getFromSource: CPU: 381 calls, 0ms, 0us/call
    -> Quantizer::getFromSource: real: 381 calls, 0.000468000R, 0.000001228R/call
    -> Quantizer::getFromSource: last: CPU: 0ms, real: 0.000002000R
    -> Segment::normalizeRests: CPU: 12 calls, 0ms, 0us/call
    -> Segment::normalizeRests: real: 12 calls, 0.011820000R, 0.000985000R/call
    -> Segment::normalizeRests: last: CPU: 0ms, real: 0.000090000R
    Profiles::dump() finished
    rosegarden: TrackEditor::paintEvent: composition is modified, update everything
    rosegarden: CompositionModelImpl::clearPreviewCache
    rosegarden (sequence manager): SequenceManager::event() with user event
    rosegarden (sequence manager): SequenceManager::event(): update requested
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus()
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: segments modified by changes to trigger segments are:
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: we have 4 segments
    rosegarden (sequence manager): SequenceManager::segmentModified(0x8f5c2a0)
    rosegarden (sequence manager): CompositionMmapper::segmentModified(0x8f5c2a0) - mmapper = 0x8f75a68
    rosegarden (sequence manager): SegmentMmapper::refresh() - /var/tmp/kde-studio//segment_8f5c2a0 - m_mmappedRegion = 0xb720c000 - m_mmappedEventBuffer = 0xb720c004 - new size = 164 - old size = 84
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f5c2a0 to 164 - current size = 84
    rosegarden (sequence manager): SegmentMmapper : remapping /var/tmp/kde-studio//segment_8f5c2a0 from size 84 to size 164
    rosegarden (sequence manager): SequenceManager::segmentModified() : size changed = true
    rosegarden (sequence manager): SequenceManager::processAddedSegment(0x8f77588)
    rosegarden (sequence manager): CompositionMmapper::segmentAdded(0x8f77588)
    rosegarden (sequence manager): CompositionMmapper::mmapSegment(0x8f77588)
    rosegarden (sequence manager): SegmentMmapper : 0x8f74ce8 trying to mmap /var/tmp/kde-studio//segment_8f77588
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f77588 to 84 - current size = 84
    rosegarden (sequence manager): SegmentMmapper::doMmap() - mmap size : 84 at 0xb720b000
    rosegarden (sequence manager): SegmentMmapper::init : mmap size = 84 for segment Acoustic Grand Piano (recorded)
    rosegarden: RosegardenGUIDoc::addRecordMIDISegment(0)
    rosegarden (sequence manager): SequenceManager::segmentAdded(0x8f6aa58)
    rosegarden: CompositionModelImpl::addRecordingItem: now have 5 recording items
    Profiler : id = EventQuantizeCommand::modifySegment - elapsed = 20ms CPU, 0.050941000R real
    rosegarden: BasicCommand(Heuristic Notation &Quantize): updated refresh statuses 7701 -> 7702
    rosegarden: BasicCommand(&Normalize Rests)::copyTo: 0x8f77588 to 0x8f5c614, range (7680,11520)
    rosegarden: BasicCommand(&Normalize Rests): updated refresh statuses 7680 -> 11520
    rosegarden: SegmentParameterBox::update()
    rosegarden (sequence manager): SequenceManager::update()
    rosegarden: RosegardenGUIDoc::slotDocumentModified()
    rosegarden: RosegardenGUIDoc[0x8dcbb60]::setModified(true)
    rosegarden: RosegardenGUIApp::slotDocumentModified(true) - doc path =
    rosegarden: MultiViewCommandHistory::addCommand: Insert Recorded MIDI
    rosegarden: BasicCommand(Heuristic Notation &Quantize)::copyTo: 0x8f6aa58 to 0x8f7a4a4, range (7701,7702)
    NotationQuantizer::Impl::quantizeRange: from time 7701 to -1
    NotationQuantizer: 1 events (0 notes), 6 passes, 1 good sets, 0 bad sets, 0ms elapsed
    Profiles::dump() :
    -> StudioControl::sendQuarterNoteLength: CPU: 1 calls, 10ms, 10000us/call
    -> StudioControl::sendQuarterNoteLength: real: 1 calls, 0.000245000R, 0.000245000R/call
    -> StudioControl::sendQuarterNoteLength: last: CPU: 10ms, real: 0.000245000R
    -> StudioControl::sendMappedComposition: CPU: 21 calls, 0ms, 0us/call
    -> StudioControl::sendMappedComposition: real: 21 calls, 0.010152000R, 0.000483429R/call
    -> StudioControl::sendMappedComposition: last: CPU: 0ms, real: 0.000028000R
    -> StudioControl::sendMappedEvent: CPU: 20 calls, 0ms, 0us/call
    -> StudioControl::sendMappedEvent: real: 20 calls, 0.010457000R, 0.000522850R/call
    -> StudioControl::sendMappedEvent: last: CPU: 0ms, real: 0.000065000R
    -> StudioControl::createStudioObject: CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::createStudioObject: real: 6 calls, 0.036230000R, 0.006038333R/call
    -> StudioControl::createStudioObject: last: CPU: 0ms, real: 0.008548000R
    -> StudioControl::setStudioObjectProperty(float): CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperty(float): real: 6 calls, 0.000402000R, 0.000067000R/call
    -> StudioControl::setStudioObjectProperty(float): last: CPU: 0ms, real: 0.000036000R
    -> StudioControl::setStudioObjectProperties(floats): CPU: 2 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperties(floats): real: 2 calls, 0.000133000R, 0.000066500R/call
    -> StudioControl::setStudioObjectProperties(floats): last: CPU: 0ms, real: 0.000034000R
    -> RosegardenGUIDoc::syncDevices: CPU: 4 calls, 210ms, 52500us/call
    -> RosegardenGUIDoc::syncDevices: real: 4 calls, 0.435456000R, 0.108864000R/call
    -> RosegardenGUIDoc::syncDevices: last: CPU: 0ms, real: 0.077598000R
    -> initialiseStudio: CPU: 2 calls, 150ms, 75000us/call
    -> initialiseStudio: real: 2 calls, 0.383968000R, 0.191984000R/call
    -> initialiseStudio: last: CPU: 0ms, real: 0.045135000R
    -> EventQuantizeCommand::modifySegment: CPU: 5 calls, 110ms, 22000us/call
    -> EventQuantizeCommand::modifySegment: real: 5 calls, 0.313305000R, 0.062661000R/call
    -> EventQuantizeCommand::modifySegment: last: CPU: 20ms, real: 0.050941000R
    -> NotationQuantizer::Impl::quantizeDuration: CPU: 36 calls, 10ms, 277.778us/call
    -> NotationQuantizer::Impl::quantizeDuration: real: 36 calls, 0.002624000R, 0.000072889R/call
    -> NotationQuantizer::Impl::quantizeDuration: last: CPU: 0ms, real: 0.000017000R
    -> NotationQuantizer::Impl::quantizeDurationProvisional: CPU: 114 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: real: 114 calls, 0.001109000R, 0.000009728R/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: last: CPU: 0ms, real: 0.000018000R
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: CPU: 571 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: real: 571 calls, 0.001620000R, 0.000002837R/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: last: CPU: 0ms, real: 0.000002000R
    -> NotationQuantizer::Impl::isValidTupletAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::isValidTupletAt: real: 10 calls, 0.000063000R, 0.000006300R/call
    -> NotationQuantizer::Impl::isValidTupletAt: last: CPU: 0ms, real: 0.000005000R
    -> NotationQuantizer::Impl::scanTupletsAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsAt: real: 10 calls, 0.000227000R, 0.000022700R/call
    -> NotationQuantizer::Impl::scanTupletsAt: last: CPU: 0ms, real: 0.000016000R
    -> NotationQuantizer::Impl::scanTupletsInBar: CPU: 6 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsInBar: real: 6 calls, 0.000305000R, 0.000050833R/call
    -> NotationQuantizer::Impl::scanTupletsInBar: last: CPU: 0ms, real: 0.000002000R
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: CPU: 114 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: real: 114 calls, 0.005102000R, 0.000044754R/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: last: CPU: 0ms, real: 0.000049000R
    -> NotationQuantizer::Impl::quantizeRange: CPU: 6 calls, 20ms, 3333.33us/call
    -> NotationQuantizer::Impl::quantizeRange: real: 6 calls, 0.025536000R, 0.004256000R/call
    -> NotationQuantizer::Impl::quantizeRange: last: CPU: 0ms, real: 0.000246000R
    -> Quantizer::setToTarget: CPU: 114 calls, 10ms, 87.7193us/call
    -> Quantizer::setToTarget: real: 114 calls, 0.008496000R, 0.000074526R/call
    -> Quantizer::setToTarget: last: CPU: 0ms, real: 0.000075000R
    -> Quantizer::getFromSource: CPU: 383 calls, 0ms, 0us/call
    -> Quantizer::getFromSource: real: 383 calls, 0.000470000R, 0.000001227R/call
    -> Quantizer::getFromSource: last: CPU: 0ms, real: 0.000001000R
    -> Segment::normalizeRests: CPU: 15 calls, 0ms, 0us/call
    -> Segment::normalizeRests: real: 15 calls, 0.011965000R, 0.000797667R/call
    -> Segment::normalizeRests: last: CPU: 0ms, real: 0.000110000R
    Profiles::dump() finished
    rosegarden: TrackEditor::paintEvent: composition is modified, update everything
    rosegarden: CompositionModelImpl::clearPreviewCache
    rosegarden (sequence manager): SequenceManager::event() with user event
    rosegarden (sequence manager): SequenceManager::event(): update requested
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus()
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: segments modified by changes to trigger segments are:
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: we have 5 segments
    rosegarden (sequence manager): SequenceManager::segmentModified(0x8f77588)
    rosegarden (sequence manager): CompositionMmapper::segmentModified(0x8f77588) - mmapper = 0x8f74ce8
    rosegarden (sequence manager): SegmentMmapper::refresh() - /var/tmp/kde-studio//segment_8f77588 - m_mmappedRegion = 0xb720b000 - m_mmappedEventBuffer = 0xb720b004 - new size = 164 - old size = 84
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f77588 to 164 - current size = 84
    rosegarden (sequence manager): SegmentMmapper : remapping /var/tmp/kde-studio//segment_8f77588 from size 84 to size 164
    rosegarden (sequence manager): SequenceManager::segmentModified() : size changed = true
    rosegarden (sequence manager): SequenceManager::processAddedSegment(0x8f6aa58)
    rosegarden (sequence manager): CompositionMmapper::segmentAdded(0x8f6aa58)
    rosegarden (sequence manager): CompositionMmapper::mmapSegment(0x8f6aa58)
    rosegarden (sequence manager): SegmentMmapper : 0x8f75250 trying to mmap /var/tmp/kde-studio//segment_8f6aa58
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f6aa58 to 84 - current size = 84
    rosegarden (sequence manager): SegmentMmapper::doMmap() - mmap size : 84 at 0xb720a000
    rosegarden (sequence manager): SegmentMmapper::init : mmap size = 84 for segment Acoustic Grand Piano (recorded)
    rosegarden: RosegardenGUIDoc::addRecordMIDISegment(0)
    rosegarden (sequence manager): SequenceManager::segmentAdded(0x8f6d2a8)
    rosegarden: CompositionModelImpl::addRecordingItem: now have 6 recording items
    Profiler : id = EventQuantizeCommand::modifySegment - elapsed = 20ms CPU, 0.047693000R real
    rosegarden: BasicCommand(Heuristic Notation &Quantize): updated refresh statuses 7701 -> 7702
    rosegarden: BasicCommand(&Normalize Rests)::copyTo: 0x8f6aa58 to 0x8f6cd64, range (7680,11520)
    rosegarden: BasicCommand(&Normalize Rests): updated refresh statuses 7680 -> 11520
    rosegarden: SegmentParameterBox::update()
    rosegarden (sequence manager): SequenceManager::update()
    rosegarden: RosegardenGUIDoc::slotDocumentModified()
    rosegarden: RosegardenGUIDoc[0x8dcbb60]::setModified(true)
    rosegarden: RosegardenGUIApp::slotDocumentModified(true) - doc path =
    rosegarden: MultiViewCommandHistory::addCommand: Insert Recorded MIDI
    rosegarden: BasicCommand(Heuristic Notation &Quantize)::copyTo: 0x8f6d2a8 to 0x8f77eb4, range (7701,7702)
    NotationQuantizer::Impl::quantizeRange: from time 7701 to -1
    NotationQuantizer: 1 events (0 notes), 6 passes, 1 good sets, 0 bad sets, 0ms elapsed
    Profiles::dump() :
    -> StudioControl::sendQuarterNoteLength: CPU: 1 calls, 10ms, 10000us/call
    -> StudioControl::sendQuarterNoteLength: real: 1 calls, 0.000245000R, 0.000245000R/call
    -> StudioControl::sendQuarterNoteLength: last: CPU: 10ms, real: 0.000245000R
    -> StudioControl::sendMappedComposition: CPU: 21 calls, 0ms, 0us/call
    -> StudioControl::sendMappedComposition: real: 21 calls, 0.010152000R, 0.000483429R/call
    -> StudioControl::sendMappedComposition: last: CPU: 0ms, real: 0.000028000R
    -> StudioControl::sendMappedEvent: CPU: 20 calls, 0ms, 0us/call
    -> StudioControl::sendMappedEvent: real: 20 calls, 0.010457000R, 0.000522850R/call
    -> StudioControl::sendMappedEvent: last: CPU: 0ms, real: 0.000065000R
    -> StudioControl::createStudioObject: CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::createStudioObject: real: 6 calls, 0.036230000R, 0.006038333R/call
    -> StudioControl::createStudioObject: last: CPU: 0ms, real: 0.008548000R
    -> StudioControl::setStudioObjectProperty(float): CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperty(float): real: 6 calls, 0.000402000R, 0.000067000R/call
    -> StudioControl::setStudioObjectProperty(float): last: CPU: 0ms, real: 0.000036000R
    -> StudioControl::setStudioObjectProperties(floats): CPU: 2 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperties(floats): real: 2 calls, 0.000133000R, 0.000066500R/call
    -> StudioControl::setStudioObjectProperties(floats): last: CPU: 0ms, real: 0.000034000R
    -> RosegardenGUIDoc::syncDevices: CPU: 4 calls, 210ms, 52500us/call
    -> RosegardenGUIDoc::syncDevices: real: 4 calls, 0.435456000R, 0.108864000R/call
    -> RosegardenGUIDoc::syncDevices: last: CPU: 0ms, real: 0.077598000R
    -> initialiseStudio: CPU: 2 calls, 150ms, 75000us/call
    -> initialiseStudio: real: 2 calls, 0.383968000R, 0.191984000R/call
    -> initialiseStudio: last: CPU: 0ms, real: 0.045135000R
    -> EventQuantizeCommand::modifySegment: CPU: 6 calls, 130ms, 21666.7us/call
    -> EventQuantizeCommand::modifySegment: real: 6 calls, 0.360998000R, 0.060166333R/call
    -> EventQuantizeCommand::modifySegment: last: CPU: 20ms, real: 0.047693000R
    -> NotationQuantizer::Impl::quantizeDuration: CPU: 36 calls, 10ms, 277.778us/call
    -> NotationQuantizer::Impl::quantizeDuration: real: 36 calls, 0.002624000R, 0.000072889R/call
    -> NotationQuantizer::Impl::quantizeDuration: last: CPU: 0ms, real: 0.000017000R
    -> NotationQuantizer::Impl::quantizeDurationProvisional: CPU: 115 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: real: 115 calls, 0.001122000R, 0.000009757R/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: last: CPU: 0ms, real: 0.000013000R
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: CPU: 576 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: real: 576 calls, 0.001635000R, 0.000002839R/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: last: CPU: 0ms, real: 0.000001000R
    -> NotationQuantizer::Impl::isValidTupletAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::isValidTupletAt: real: 10 calls, 0.000063000R, 0.000006300R/call
    -> NotationQuantizer::Impl::isValidTupletAt: last: CPU: 0ms, real: 0.000005000R
    -> NotationQuantizer::Impl::scanTupletsAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsAt: real: 10 calls, 0.000227000R, 0.000022700R/call
    -> NotationQuantizer::Impl::scanTupletsAt: last: CPU: 0ms, real: 0.000016000R
    -> NotationQuantizer::Impl::scanTupletsInBar: CPU: 7 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsInBar: real: 7 calls, 0.000308000R, 0.000044000R/call
    -> NotationQuantizer::Impl::scanTupletsInBar: last: CPU: 0ms, real: 0.000003000R
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: CPU: 115 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: real: 115 calls, 0.005158000R, 0.000044852R/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: last: CPU: 0ms, real: 0.000056000R
    -> NotationQuantizer::Impl::quantizeRange: CPU: 7 calls, 20ms, 2857.14us/call
    -> NotationQuantizer::Impl::quantizeRange: real: 7 calls, 0.025783000R, 0.003683286R/call
    -> NotationQuantizer::Impl::quantizeRange: last: CPU: 0ms, real: 0.000247000R
    -> Quantizer::setToTarget: CPU: 115 calls, 10ms, 86.9565us/call
    -> Quantizer::setToTarget: real: 115 calls, 0.008571000R, 0.000074530R/call
    -> Quantizer::setToTarget: last: CPU: 0ms, real: 0.000075000R
    -> Quantizer::getFromSource: CPU: 385 calls, 0ms, 0us/call
    -> Quantizer::getFromSource: real: 385 calls, 0.000472000R, 0.000001226R/call
    -> Quantizer::getFromSource: last: CPU: 0ms, real: 0.000001000R
    -> Segment::normalizeRests: CPU: 18 calls, 0ms, 0us/call
    -> Segment::normalizeRests: real: 18 calls, 0.012103000R, 0.000672389R/call
    -> Segment::normalizeRests: last: CPU: 0ms, real: 0.000104000R
    Profiles::dump() finished
    rosegarden: TrackEditor::paintEvent: composition is modified, update everything
    rosegarden: CompositionModelImpl::clearPreviewCache
    rosegarden (sequence manager): SequenceManager::event() with user event
    rosegarden (sequence manager): SequenceManager::event(): update requested
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus()
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: segments modified by changes to trigger segments are:
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: we have 6 segments
    rosegarden (sequence manager): SequenceManager::segmentModified(0x8f6aa58)
    rosegarden (sequence manager): CompositionMmapper::segmentModified(0x8f6aa58) - mmapper = 0x8f75250
    rosegarden (sequence manager): SegmentMmapper::refresh() - /var/tmp/kde-studio//segment_8f6aa58 - m_mmappedRegion = 0xb720a000 - m_mmappedEventBuffer = 0xb720a004 - new size = 164 - old size = 84
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f6aa58 to 164 - current size = 84
    rosegarden (sequence manager): SegmentMmapper : remapping /var/tmp/kde-studio//segment_8f6aa58 from size 84 to size 164
    rosegarden (sequence manager): SequenceManager::segmentModified() : size changed = true
    rosegarden (sequence manager): SequenceManager::processAddedSegment(0x8f6d2a8)
    rosegarden (sequence manager): CompositionMmapper::segmentAdded(0x8f6d2a8)
    rosegarden (sequence manager): CompositionMmapper::mmapSegment(0x8f6d2a8)
    rosegarden (sequence manager): SegmentMmapper : 0x8f74e90 trying to mmap /var/tmp/kde-studio//segment_8f6d2a8
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f6d2a8 to 84 - current size = 84
    rosegarden (sequence manager): SegmentMmapper::doMmap() - mmap size : 84 at 0xb7209000
    rosegarden (sequence manager): SegmentMmapper::init : mmap size = 84 for segment Acoustic Grand Piano (recorded)
    rosegarden: RosegardenGUIDoc::addRecordMIDISegment(0)
    rosegarden (sequence manager): SequenceManager::segmentAdded(0x8f6ad68)
    rosegarden: CompositionModelImpl::addRecordingItem: now have 7 recording items
    Profiler : id = EventQuantizeCommand::modifySegment - elapsed = 30ms CPU, 0.048820000R real
    rosegarden: BasicCommand(Heuristic Notation &Quantize): updated refresh statuses 7701 -> 7702
    rosegarden: BasicCommand(&Normalize Rests)::copyTo: 0x8f6d2a8 to 0x8f778fc, range (7680,11520)
    rosegarden: BasicCommand(&Normalize Rests): updated refresh statuses 7680 -> 11520
    rosegarden: SegmentParameterBox::update()
    rosegarden (sequence manager): SequenceManager::update()
    rosegarden: RosegardenGUIDoc::slotDocumentModified()
    rosegarden: RosegardenGUIDoc[0x8dcbb60]::setModified(true)
    rosegarden: RosegardenGUIApp::slotDocumentModified(true) - doc path =
    rosegarden: MultiViewCommandHistory::addCommand: Insert Recorded MIDI
    rosegarden: BasicCommand(Heuristic Notation &Quantize)::copyTo: 0x8f6ad68 to 0x8f6b42c, range (7701,7702)
    NotationQuantizer::Impl::quantizeRange: from time 7701 to -1
    NotationQuantizer: 1 events (0 notes), 6 passes, 1 good sets, 0 bad sets, 0ms elapsed
    Profiles::dump() :
    -> StudioControl::sendQuarterNoteLength: CPU: 1 calls, 10ms, 10000us/call
    -> StudioControl::sendQuarterNoteLength: real: 1 calls, 0.000245000R, 0.000245000R/call
    -> StudioControl::sendQuarterNoteLength: last: CPU: 10ms, real: 0.000245000R
    -> StudioControl::sendMappedComposition: CPU: 21 calls, 0ms, 0us/call
    -> StudioControl::sendMappedComposition: real: 21 calls, 0.010152000R, 0.000483429R/call
    -> StudioControl::sendMappedComposition: last: CPU: 0ms, real: 0.000028000R
    -> StudioControl::sendMappedEvent: CPU: 20 calls, 0ms, 0us/call
    -> StudioControl::sendMappedEvent: real: 20 calls, 0.010457000R, 0.000522850R/call
    -> StudioControl::sendMappedEvent: last: CPU: 0ms, real: 0.000065000R
    -> StudioControl::createStudioObject: CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::createStudioObject: real: 6 calls, 0.036230000R, 0.006038333R/call
    -> StudioControl::createStudioObject: last: CPU: 0ms, real: 0.008548000R
    -> StudioControl::setStudioObjectProperty(float): CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperty(float): real: 6 calls, 0.000402000R, 0.000067000R/call
    -> StudioControl::setStudioObjectProperty(float): last: CPU: 0ms, real: 0.000036000R
    -> StudioControl::setStudioObjectProperties(floats): CPU: 2 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperties(floats): real: 2 calls, 0.000133000R, 0.000066500R/call
    -> StudioControl::setStudioObjectProperties(floats): last: CPU: 0ms, real: 0.000034000R
    -> RosegardenGUIDoc::syncDevices: CPU: 4 calls, 210ms, 52500us/call
    -> RosegardenGUIDoc::syncDevices: real: 4 calls, 0.435456000R, 0.108864000R/call
    -> RosegardenGUIDoc::syncDevices: last: CPU: 0ms, real: 0.077598000R
    -> initialiseStudio: CPU: 2 calls, 150ms, 75000us/call
    -> initialiseStudio: real: 2 calls, 0.383968000R, 0.191984000R/call
    -> initialiseStudio: last: CPU: 0ms, real: 0.045135000R
    -> EventQuantizeCommand::modifySegment: CPU: 7 calls, 160ms, 22857.1us/call
    -> EventQuantizeCommand::modifySegment: real: 7 calls, 0.409818000R, 0.058545429R/call
    -> EventQuantizeCommand::modifySegment: last: CPU: 30ms, real: 0.048820000R
    -> NotationQuantizer::Impl::quantizeDuration: CPU: 36 calls, 10ms, 277.778us/call
    -> NotationQuantizer::Impl::quantizeDuration: real: 36 calls, 0.002624000R, 0.000072889R/call
    -> NotationQuantizer::Impl::quantizeDuration: last: CPU: 0ms, real: 0.000017000R
    -> NotationQuantizer::Impl::quantizeDurationProvisional: CPU: 116 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: real: 116 calls, 0.001136000R, 0.000009793R/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: last: CPU: 0ms, real: 0.000014000R
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: CPU: 581 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: real: 581 calls, 0.001645000R, 0.000002831R/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: last: CPU: 0ms, real: 0.000001000R
    -> NotationQuantizer::Impl::isValidTupletAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::isValidTupletAt: real: 10 calls, 0.000063000R, 0.000006300R/call
    -> NotationQuantizer::Impl::isValidTupletAt: last: CPU: 0ms, real: 0.000005000R
    -> NotationQuantizer::Impl::scanTupletsAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsAt: real: 10 calls, 0.000227000R, 0.000022700R/call
    -> NotationQuantizer::Impl::scanTupletsAt: last: CPU: 0ms, real: 0.000016000R
    -> NotationQuantizer::Impl::scanTupletsInBar: CPU: 8 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsInBar: real: 8 calls, 0.000311000R, 0.000038875R/call
    -> NotationQuantizer::Impl::scanTupletsInBar: last: CPU: 0ms, real: 0.000003000R
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: CPU: 116 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: real: 116 calls, 0.005203000R, 0.000044853R/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: last: CPU: 0ms, real: 0.000045000R
    -> NotationQuantizer::Impl::quantizeRange: CPU: 8 calls, 20ms, 2500us/call
    -> NotationQuantizer::Impl::quantizeRange: real: 8 calls, 0.026014000R, 0.003251750R/call
    -> NotationQuantizer::Impl::quantizeRange: last: CPU: 0ms, real: 0.000231000R
    -> Quantizer::setToTarget: CPU: 116 calls, 10ms, 86.2069us/call
    -> Quantizer::setToTarget: real: 116 calls, 0.008645000R, 0.000074526R/call
    -> Quantizer::setToTarget: last: CPU: 0ms, real: 0.000074000R
    -> Quantizer::getFromSource: CPU: 387 calls, 0ms, 0us/call
    -> Quantizer::getFromSource: real: 387 calls, 0.000474000R, 0.000001225R/call
    -> Quantizer::getFromSource: last: CPU: 0ms, real: 0.000001000R
    -> Segment::normalizeRests: CPU: 21 calls, 0ms, 0us/call
    -> Segment::normalizeRests: real: 21 calls, 0.012255000R, 0.000583571R/call
    -> Segment::normalizeRests: last: CPU: 0ms, real: 0.000118000R
    Profiles::dump() finished
    rosegarden: TrackEditor::paintEvent: composition is modified, update everything
    rosegarden: CompositionModelImpl::clearPreviewCache
    rosegarden (sequence manager): SequenceManager::event() with user event
    rosegarden (sequence manager): SequenceManager::event(): update requested
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus()
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: segments modified by changes to trigger segments are:
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: we have 7 segments
    rosegarden (sequence manager): SequenceManager::segmentModified(0x8f6d2a8)
    rosegarden (sequence manager): CompositionMmapper::segmentModified(0x8f6d2a8) - mmapper = 0x8f74e90
    rosegarden (sequence manager): SegmentMmapper::refresh() - /var/tmp/kde-studio//segment_8f6d2a8 - m_mmappedRegion = 0xb7209000 - m_mmappedEventBuffer = 0xb7209004 - new size = 164 - old size = 84
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f6d2a8 to 164 - current size = 84
    rosegarden (sequence manager): SegmentMmapper : remapping /var/tmp/kde-studio//segment_8f6d2a8 from size 84 to size 164
    rosegarden (sequence manager): SequenceManager::segmentModified() : size changed = true
    rosegarden (sequence manager): SequenceManager::processAddedSegment(0x8f6ad68)
    rosegarden (sequence manager): CompositionMmapper::segmentAdded(0x8f6ad68)
    rosegarden (sequence manager): CompositionMmapper::mmapSegment(0x8f6ad68)
    rosegarden (sequence manager): SegmentMmapper : 0x8f778a0 trying to mmap /var/tmp/kde-studio//segment_8f6ad68
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f6ad68 to 84 - current size = 84
    rosegarden (sequence manager): SegmentMmapper::doMmap() - mmap size : 84 at 0xb7208000
    rosegarden (sequence manager): SegmentMmapper::init : mmap size = 84 for segment Acoustic Grand Piano (recorded)
    rosegarden: RosegardenGUIDoc::addRecordMIDISegment(0)
    rosegarden (sequence manager): SequenceManager::segmentAdded(0x8f79ab0)
    rosegarden: CompositionModelImpl::addRecordingItem: now have 8 recording items
    Profiler : id = EventQuantizeCommand::modifySegment - elapsed = 30ms CPU, 0.228176000R real
    rosegarden: BasicCommand(Heuristic Notation &Quantize): updated refresh statuses 7701 -> 7702
    rosegarden: BasicCommand(&Normalize Rests)::copyTo: 0x8f6ad68 to 0x8f76ebc, range (7680,11520)
    rosegarden: BasicCommand(&Normalize Rests): updated refresh statuses 7680 -> 11520
    rosegarden: SegmentParameterBox::update()
    rosegarden (sequence manager): SequenceManager::update()
    rosegarden: RosegardenGUIDoc::slotDocumentModified()
    rosegarden: RosegardenGUIDoc[0x8dcbb60]::setModified(true)
    rosegarden: RosegardenGUIApp::slotDocumentModified(true) - doc path =
    rosegarden: MultiViewCommandHistory::addCommand: Insert Recorded MIDI
    rosegarden: BasicCommand(Heuristic Notation &Quantize)::copyTo: 0x8f79ab0 to 0x8f6bb34, range (7701,7702)
    NotationQuantizer::Impl::quantizeRange: from time 7701 to -1
    NotationQuantizer: 1 events (0 notes), 6 passes, 1 good sets, 0 bad sets, 0ms elapsed
    Profiles::dump() :
    -> StudioControl::sendQuarterNoteLength: CPU: 1 calls, 10ms, 10000us/call
    -> StudioControl::sendQuarterNoteLength: real: 1 calls, 0.000245000R, 0.000245000R/call
    -> StudioControl::sendQuarterNoteLength: last: CPU: 10ms, real: 0.000245000R
    -> StudioControl::sendMappedComposition: CPU: 21 calls, 0ms, 0us/call
    -> StudioControl::sendMappedComposition: real: 21 calls, 0.010152000R, 0.000483429R/call
    -> StudioControl::sendMappedComposition: last: CPU: 0ms, real: 0.000028000R
    -> StudioControl::sendMappedEvent: CPU: 20 calls, 0ms, 0us/call
    -> StudioControl::sendMappedEvent: real: 20 calls, 0.010457000R, 0.000522850R/call
    -> StudioControl::sendMappedEvent: last: CPU: 0ms, real: 0.000065000R
    -> StudioControl::createStudioObject: CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::createStudioObject: real: 6 calls, 0.036230000R, 0.006038333R/call
    -> StudioControl::createStudioObject: last: CPU: 0ms, real: 0.008548000R
    -> StudioControl::setStudioObjectProperty(float): CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperty(float): real: 6 calls, 0.000402000R, 0.000067000R/call
    -> StudioControl::setStudioObjectProperty(float): last: CPU: 0ms, real: 0.000036000R
    -> StudioControl::setStudioObjectProperties(floats): CPU: 2 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperties(floats): real: 2 calls, 0.000133000R, 0.000066500R/call
    -> StudioControl::setStudioObjectProperties(floats): last: CPU: 0ms, real: 0.000034000R
    -> RosegardenGUIDoc::syncDevices: CPU: 4 calls, 210ms, 52500us/call
    -> RosegardenGUIDoc::syncDevices: real: 4 calls, 0.435456000R, 0.108864000R/call
    -> RosegardenGUIDoc::syncDevices: last: CPU: 0ms, real: 0.077598000R
    -> initialiseStudio: CPU: 2 calls, 150ms, 75000us/call
    -> initialiseStudio: real: 2 calls, 0.383968000R, 0.191984000R/call
    -> initialiseStudio: last: CPU: 0ms, real: 0.045135000R
    -> EventQuantizeCommand::modifySegment: CPU: 8 calls, 190ms, 23750us/call
    -> EventQuantizeCommand::modifySegment: real: 8 calls, 0.637994000R, 0.079749250R/call
    -> EventQuantizeCommand::modifySegment: last: CPU: 30ms, real: 0.228176000R
    -> NotationQuantizer::Impl::quantizeDuration: CPU: 36 calls, 10ms, 277.778us/call
    -> NotationQuantizer::Impl::quantizeDuration: real: 36 calls, 0.002624000R, 0.000072889R/call
    -> NotationQuantizer::Impl::quantizeDuration: last: CPU: 0ms, real: 0.000017000R
    -> NotationQuantizer::Impl::quantizeDurationProvisional: CPU: 117 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: real: 117 calls, 0.001150000R, 0.000009829R/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: last: CPU: 0ms, real: 0.000014000R
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: CPU: 586 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: real: 586 calls, 0.001656000R, 0.000002826R/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: last: CPU: 0ms, real: 0.000001000R
    -> NotationQuantizer::Impl::isValidTupletAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::isValidTupletAt: real: 10 calls, 0.000063000R, 0.000006300R/call
    -> NotationQuantizer::Impl::isValidTupletAt: last: CPU: 0ms, real: 0.000005000R
    -> NotationQuantizer::Impl::scanTupletsAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsAt: real: 10 calls, 0.000227000R, 0.000022700R/call
    -> NotationQuantizer::Impl::scanTupletsAt: last: CPU: 0ms, real: 0.000016000R
    -> NotationQuantizer::Impl::scanTupletsInBar: CPU: 9 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsInBar: real: 9 calls, 0.000313000R, 0.000034778R/call
    -> NotationQuantizer::Impl::scanTupletsInBar: last: CPU: 0ms, real: 0.000002000R
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: CPU: 117 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: real: 117 calls, 0.005250000R, 0.000044872R/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: last: CPU: 0ms, real: 0.000047000R
    -> NotationQuantizer::Impl::quantizeRange: CPU: 9 calls, 20ms, 2222.22us/call
    -> NotationQuantizer::Impl::quantizeRange: real: 9 calls, 0.027216000R, 0.003024000R/call
    -> NotationQuantizer::Impl::quantizeRange: last: CPU: 0ms, real: 0.001202000R
    -> Quantizer::setToTarget: CPU: 117 calls, 10ms, 85.4701us/call
    -> Quantizer::setToTarget: real: 117 calls, 0.008727000R, 0.000074590R/call
    -> Quantizer::setToTarget: last: CPU: 0ms, real: 0.000082000R
    -> Quantizer::getFromSource: CPU: 389 calls, 0ms, 0us/call
    -> Quantizer::getFromSource: real: 389 calls, 0.000476000R, 0.000001224R/call
    -> Quantizer::getFromSource: last: CPU: 0ms, real: 0.000001000R
    -> Segment::normalizeRests: CPU: 24 calls, 0ms, 0us/call
    -> Segment::normalizeRests: real: 24 calls, 0.012386000R, 0.000516083R/call
    -> Segment::normalizeRests: last: CPU: 0ms, real: 0.000094000R
    Profiles::dump() finished
    rosegarden: TrackEditor::paintEvent: composition is modified, update everything
    rosegarden: CompositionModelImpl::clearPreviewCache
    rosegarden (sequence manager): SequenceManager::event() with user event
    rosegarden (sequence manager): SequenceManager::event(): update requested
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus()
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: segments modified by changes to trigger segments are:
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: we have 8 segments
    rosegarden (sequence manager): SequenceManager::segmentModified(0x8f6ad68)
    rosegarden (sequence manager): CompositionMmapper::segmentModified(0x8f6ad68) - mmapper = 0x8f778a0
    rosegarden (sequence manager): SegmentMmapper::refresh() - /var/tmp/kde-studio//segment_8f6ad68 - m_mmappedRegion = 0xb7208000 - m_mmappedEventBuffer = 0xb7208004 - new size = 164 - old size = 84
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f6ad68 to 164 - current size = 84
    rosegarden (sequence manager): SegmentMmapper : remapping /var/tmp/kde-studio//segment_8f6ad68 from size 84 to size 164
    rosegarden (sequence manager): SequenceManager::segmentModified() : size changed = true
    rosegarden (sequence manager): SequenceManager::processAddedSegment(0x8f79ab0)
    rosegarden (sequence manager): CompositionMmapper::segmentAdded(0x8f79ab0)
    rosegarden (sequence manager): CompositionMmapper::mmapSegment(0x8f79ab0)
    rosegarden (sequence manager): SegmentMmapper : 0x8f79610 trying to mmap /var/tmp/kde-studio//segment_8f79ab0
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f79ab0 to 84 - current size = 84
    rosegarden (sequence manager): SegmentMmapper::doMmap() - mmap size : 84 at 0xb7207000
    rosegarden (sequence manager): SegmentMmapper::init : mmap size = 84 for segment Acoustic Grand Piano (recorded)
    rosegarden: RosegardenGUIDoc::addRecordMIDISegment(0)
    rosegarden (sequence manager): SequenceManager::segmentAdded(0x8f6b7e0)
    rosegarden: CompositionModelImpl::addRecordingItem: now have 9 recording items
    Profiler : id = EventQuantizeCommand::modifySegment - elapsed = 30ms CPU, 0.073683000R real
    rosegarden: BasicCommand(Heuristic Notation &Quantize): updated refresh statuses 7701 -> 7702
    rosegarden: BasicCommand(&Normalize Rests)::copyTo: 0x8f79ab0 to 0x8f7688c, range (7680,11520)
    rosegarden: BasicCommand(&Normalize Rests): updated refresh statuses 7680 -> 11520
    rosegarden: SegmentParameterBox::update()
    rosegarden (sequence manager): SequenceManager::update()
    rosegarden: RosegardenGUIDoc::slotDocumentModified()
    rosegarden: RosegardenGUIDoc[0x8dcbb60]::setModified(true)
    rosegarden: RosegardenGUIApp::slotDocumentModified(true) - doc path =
    rosegarden: MultiViewCommandHistory::addCommand: Insert Recorded MIDI
    rosegarden: BasicCommand(Heuristic Notation &Quantize)::copyTo: 0x8f6b7e0 to 0x8f7c444, range (7701,7702)
    NotationQuantizer::Impl::quantizeRange: from time 7701 to -1
    NotationQuantizer: 1 events (0 notes), 6 passes, 1 good sets, 0 bad sets, 0ms elapsed
    Profiles::dump() :
    -> StudioControl::sendQuarterNoteLength: CPU: 1 calls, 10ms, 10000us/call
    -> StudioControl::sendQuarterNoteLength: real: 1 calls, 0.000245000R, 0.000245000R/call
    -> StudioControl::sendQuarterNoteLength: last: CPU: 10ms, real: 0.000245000R
    -> StudioControl::sendMappedComposition: CPU: 21 calls, 0ms, 0us/call
    -> StudioControl::sendMappedComposition: real: 21 calls, 0.010152000R, 0.000483429R/call
    -> StudioControl::sendMappedComposition: last: CPU: 0ms, real: 0.000028000R
    -> StudioControl::sendMappedEvent: CPU: 20 calls, 0ms, 0us/call
    -> StudioControl::sendMappedEvent: real: 20 calls, 0.010457000R, 0.000522850R/call
    -> StudioControl::sendMappedEvent: last: CPU: 0ms, real: 0.000065000R
    -> StudioControl::createStudioObject: CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::createStudioObject: real: 6 calls, 0.036230000R, 0.006038333R/call
    -> StudioControl::createStudioObject: last: CPU: 0ms, real: 0.008548000R
    -> StudioControl::setStudioObjectProperty(float): CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperty(float): real: 6 calls, 0.000402000R, 0.000067000R/call
    -> StudioControl::setStudioObjectProperty(float): last: CPU: 0ms, real: 0.000036000R
    -> StudioControl::setStudioObjectProperties(floats): CPU: 2 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperties(floats): real: 2 calls, 0.000133000R, 0.000066500R/call
    -> StudioControl::setStudioObjectProperties(floats): last: CPU: 0ms, real: 0.000034000R
    -> RosegardenGUIDoc::syncDevices: CPU: 4 calls, 210ms, 52500us/call
    -> RosegardenGUIDoc::syncDevices: real: 4 calls, 0.435456000R, 0.108864000R/call
    -> RosegardenGUIDoc::syncDevices: last: CPU: 0ms, real: 0.077598000R
    -> initialiseStudio: CPU: 2 calls, 150ms, 75000us/call
    -> initialiseStudio: real: 2 calls, 0.383968000R, 0.191984000R/call
    -> initialiseStudio: last: CPU: 0ms, real: 0.045135000R
    -> EventQuantizeCommand::modifySegment: CPU: 9 calls, 220ms, 24444.4us/call
    -> EventQuantizeCommand::modifySegment: real: 9 calls, 0.711677000R, 0.079075222R/call
    -> EventQuantizeCommand::modifySegment: last: CPU: 30ms, real: 0.073683000R
    -> NotationQuantizer::Impl::quantizeDuration: CPU: 36 calls, 10ms, 277.778us/call
    -> NotationQuantizer::Impl::quantizeDuration: real: 36 calls, 0.002624000R, 0.000072889R/call
    -> NotationQuantizer::Impl::quantizeDuration: last: CPU: 0ms, real: 0.000017000R
    -> NotationQuantizer::Impl::quantizeDurationProvisional: CPU: 118 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: real: 118 calls, 0.001164000R, 0.000009864R/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: last: CPU: 0ms, real: 0.000014000R
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: CPU: 591 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: real: 591 calls, 0.001666000R, 0.000002819R/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: last: CPU: 0ms, real: 0.000001000R
    -> NotationQuantizer::Impl::isValidTupletAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::isValidTupletAt: real: 10 calls, 0.000063000R, 0.000006300R/call
    -> NotationQuantizer::Impl::isValidTupletAt: last: CPU: 0ms, real: 0.000005000R
    -> NotationQuantizer::Impl::scanTupletsAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsAt: real: 10 calls, 0.000227000R, 0.000022700R/call
    -> NotationQuantizer::Impl::scanTupletsAt: last: CPU: 0ms, real: 0.000016000R
    -> NotationQuantizer::Impl::scanTupletsInBar: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsInBar: real: 10 calls, 0.000315000R, 0.000031500R/call
    -> NotationQuantizer::Impl::scanTupletsInBar: last: CPU: 0ms, real: 0.000002000R
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: CPU: 118 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: real: 118 calls, 0.005296000R, 0.000044881R/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: last: CPU: 0ms, real: 0.000046000R
    -> NotationQuantizer::Impl::quantizeRange: CPU: 10 calls, 20ms, 2000us/call
    -> NotationQuantizer::Impl::quantizeRange: real: 10 calls, 0.028366000R, 0.002836600R/call
    -> NotationQuantizer::Impl::quantizeRange: last: CPU: 0ms, real: 0.001150000R
    -> Quantizer::setToTarget: CPU: 118 calls, 10ms, 84.7458us/call
    -> Quantizer::setToTarget: real: 118 calls, 0.008807000R, 0.000074636R/call
    -> Quantizer::setToTarget: last: CPU: 0ms, real: 0.000080000R
    -> Quantizer::getFromSource: CPU: 391 calls, 0ms, 0us/call
    -> Quantizer::getFromSource: real: 391 calls, 0.000478000R, 0.000001223R/call
    -> Quantizer::getFromSource: last: CPU: 0ms, real: 0.000001000R
    -> Segment::normalizeRests: CPU: 27 calls, 0ms, 0us/call
    -> Segment::normalizeRests: real: 27 calls, 0.012517000R, 0.000463593R/call
    -> Segment::normalizeRests: last: CPU: 0ms, real: 0.000100000R
    Profiles::dump() finished
    rosegarden: TrackEditor::paintEvent: composition is modified, update everything
    rosegarden: CompositionModelImpl::clearPreviewCache
    rosegarden (sequence manager): SequenceManager::event() with user event
    rosegarden (sequence manager): SequenceManager::event(): update requested
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus()
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: segments modified by changes to trigger segments are:
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: we have 9 segments
    rosegarden (sequence manager): SequenceManager::segmentModified(0x8f79ab0)
    rosegarden (sequence manager): CompositionMmapper::segmentModified(0x8f79ab0) - mmapper = 0x8f79610
    rosegarden (sequence manager): SegmentMmapper::refresh() - /var/tmp/kde-studio//segment_8f79ab0 - m_mmappedRegion = 0xb7207000 - m_mmappedEventBuffer = 0xb7207004 - new size = 164 - old size = 84
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f79ab0 to 164 - current size = 84
    rosegarden (sequence manager): SegmentMmapper : remapping /var/tmp/kde-studio//segment_8f79ab0 from size 84 to size 164
    rosegarden (sequence manager): SequenceManager::segmentModified() : size changed = true
    rosegarden (sequence manager): SequenceManager::processAddedSegment(0x8f6b7e0)
    rosegarden (sequence manager): CompositionMmapper::segmentAdded(0x8f6b7e0)
    rosegarden (sequence manager): CompositionMmapper::mmapSegment(0x8f6b7e0)
    rosegarden (sequence manager): SegmentMmapper : 0x8f77a98 trying to mmap /var/tmp/kde-studio//segment_8f6b7e0
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f6b7e0 to 84 - current size = 84
    rosegarden (sequence manager): SegmentMmapper::doMmap() - mmap size : 84 at 0xb7206000
    rosegarden (sequence manager): SegmentMmapper::init : mmap size = 84 for segment Acoustic Grand Piano (recorded)
    rosegarden: RosegardenGUIDoc::addRecordMIDISegment(0)
    rosegarden (sequence manager): SequenceManager::segmentAdded(0x8f6b300)
    rosegarden: CompositionModelImpl::addRecordingItem: now have 10 recording items
    Profiler : id = EventQuantizeCommand::modifySegment - elapsed = 30ms CPU, 0.077248000R real
    rosegarden: BasicCommand(Heuristic Notation &Quantize): updated refresh statuses 7701 -> 7702
    rosegarden: BasicCommand(&Normalize Rests)::copyTo: 0x8f6b7e0 to 0x8f7e2b4, range (7680,11520)
    rosegarden: BasicCommand(&Normalize Rests): updated refresh statuses 7680 -> 11520
    rosegarden: SegmentParameterBox::update()
    rosegarden (sequence manager): SequenceManager::update()
    rosegarden: RosegardenGUIDoc::slotDocumentModified()
    rosegarden: RosegardenGUIDoc[0x8dcbb60]::setModified(true)
    rosegarden: RosegardenGUIApp::slotDocumentModified(true) - doc path =
    rosegarden: MultiViewCommandHistory::addCommand: Insert Recorded MIDI
    rosegarden: BasicCommand(Heuristic Notation &Quantize)::copyTo: 0x8f6b300 to 0x8f76dbc, range (7701,7702)
    NotationQuantizer::Impl::quantizeRange: from time 7701 to -1
    NotationQuantizer: 1 events (0 notes), 6 passes, 1 good sets, 0 bad sets, 10ms elapsed
    Profiles::dump() :
    -> StudioControl::sendQuarterNoteLength: CPU: 1 calls, 10ms, 10000us/call
    -> StudioControl::sendQuarterNoteLength: real: 1 calls, 0.000245000R, 0.000245000R/call
    -> StudioControl::sendQuarterNoteLength: last: CPU: 10ms, real: 0.000245000R
    -> StudioControl::sendMappedComposition: CPU: 21 calls, 0ms, 0us/call
    -> StudioControl::sendMappedComposition: real: 21 calls, 0.010152000R, 0.000483429R/call
    -> StudioControl::sendMappedComposition: last: CPU: 0ms, real: 0.000028000R
    -> StudioControl::sendMappedEvent: CPU: 20 calls, 0ms, 0us/call
    -> StudioControl::sendMappedEvent: real: 20 calls, 0.010457000R, 0.000522850R/call
    -> StudioControl::sendMappedEvent: last: CPU: 0ms, real: 0.000065000R
    -> StudioControl::createStudioObject: CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::createStudioObject: real: 6 calls, 0.036230000R, 0.006038333R/call
    -> StudioControl::createStudioObject: last: CPU: 0ms, real: 0.008548000R
    -> StudioControl::setStudioObjectProperty(float): CPU: 6 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperty(float): real: 6 calls, 0.000402000R, 0.000067000R/call
    -> StudioControl::setStudioObjectProperty(float): last: CPU: 0ms, real: 0.000036000R
    -> StudioControl::setStudioObjectProperties(floats): CPU: 2 calls, 0ms, 0us/call
    -> StudioControl::setStudioObjectProperties(floats): real: 2 calls, 0.000133000R, 0.000066500R/call
    -> StudioControl::setStudioObjectProperties(floats): last: CPU: 0ms, real: 0.000034000R
    -> RosegardenGUIDoc::syncDevices: CPU: 4 calls, 210ms, 52500us/call
    -> RosegardenGUIDoc::syncDevices: real: 4 calls, 0.435456000R, 0.108864000R/call
    -> RosegardenGUIDoc::syncDevices: last: CPU: 0ms, real: 0.077598000R
    -> initialiseStudio: CPU: 2 calls, 150ms, 75000us/call
    -> initialiseStudio: real: 2 calls, 0.383968000R, 0.191984000R/call
    -> initialiseStudio: last: CPU: 0ms, real: 0.045135000R
    -> EventQuantizeCommand::modifySegment: CPU: 10 calls, 250ms, 25000us/call
    -> EventQuantizeCommand::modifySegment: real: 10 calls, 0.788925000R, 0.078892500R/call
    -> EventQuantizeCommand::modifySegment: last: CPU: 30ms, real: 0.077248000R
    -> NotationQuantizer::Impl::quantizeDuration: CPU: 36 calls, 10ms, 277.778us/call
    -> NotationQuantizer::Impl::quantizeDuration: real: 36 calls, 0.002624000R, 0.000072889R/call
    -> NotationQuantizer::Impl::quantizeDuration: last: CPU: 0ms, real: 0.000017000R
    -> NotationQuantizer::Impl::quantizeDurationProvisional: CPU: 119 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: real: 119 calls, 0.001178000R, 0.000009899R/call
    -> NotationQuantizer::Impl::quantizeDurationProvisional: last: CPU: 0ms, real: 0.000014000R
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: CPU: 596 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: real: 596 calls, 0.001677000R, 0.000002814R/call
    -> NotationQuantizer::Impl::scoreAbsoluteTimeForBase: last: CPU: 0ms, real: 0.000002000R
    -> NotationQuantizer::Impl::isValidTupletAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::isValidTupletAt: real: 10 calls, 0.000063000R, 0.000006300R/call
    -> NotationQuantizer::Impl::isValidTupletAt: last: CPU: 0ms, real: 0.000005000R
    -> NotationQuantizer::Impl::scanTupletsAt: CPU: 10 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsAt: real: 10 calls, 0.000227000R, 0.000022700R/call
    -> NotationQuantizer::Impl::scanTupletsAt: last: CPU: 0ms, real: 0.000016000R
    -> NotationQuantizer::Impl::scanTupletsInBar: CPU: 11 calls, 0ms, 0us/call
    -> NotationQuantizer::Impl::scanTupletsInBar: real: 11 calls, 0.000318000R, 0.000028909R/call
    -> NotationQuantizer::Impl::scanTupletsInBar: last: CPU: 0ms, real: 0.000003000R
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: CPU: 119 calls, 10ms, 84.0336us/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: real: 119 calls, 0.005354000R, 0.000044992R/call
    -> NotationQuantizer::Impl::quantizeAbsoluteTime: last: CPU: 10ms, real: 0.000058000R
    -> NotationQuantizer::Impl::quantizeRange: CPU: 11 calls, 30ms, 2727.27us/call
    -> NotationQuantizer::Impl::quantizeRange: real: 11 calls, 0.028616000R, 0.002601455R/call
    -> NotationQuantizer::Impl::quantizeRange: last: CPU: 10ms, real: 0.000250000R
    -> Quantizer::setToTarget: CPU: 119 calls, 10ms, 84.0336us/call
    -> Quantizer::setToTarget: real: 119 calls, 0.008882000R, 0.000074639R/call
    -> Quantizer::setToTarget: last: CPU: 0ms, real: 0.000075000R
    -> Quantizer::getFromSource: CPU: 393 calls, 0ms, 0us/call
    -> Quantizer::getFromSource: real: 393 calls, 0.000481000R, 0.000001224R/call
    -> Quantizer::getFromSource: last: CPU: 0ms, real: 0.000002000R
    -> Segment::normalizeRests: CPU: 30 calls, 0ms, 0us/call
    Profiles::dump() finished
    Profiler : id = EventQuantizeCommand::modifySegment - elapsed = 10ms CPU, 0.144654000R real
    rosegarden: BasicCommand(Heuristic Notation &Quantize): updated refresh statuses 7701 -> 7702
    rosegarden: BasicCommand(&Normalize Rests)::copyTo: 0x8f6b300 to 0x8f7e07c, range (7680,11520)
    rosegarden: BasicCommand(&Normalize Rests): updated refresh statuses 7680 -> 11520
    rosegarden: SegmentParameterBox::update()
    rosegarden (sequence manager): SequenceManager::update()
    rosegarden: RosegardenGUIDoc::slotDocumentModified()
    rosegarden: RosegardenGUIDoc[0x8dcbb60]::setModified(true)
    rosegarden: RosegardenGUIApp::slotDocumentModified(true) - doc path =
    rosegarden: CompositionModelImpl::clearRecordingItem
    rosegarden: RosegardenGUIDoc::stopRecordingAudio
    rosegarden: CompositionModelImpl::clearRecordingItem
    rosegarden: TrackEditor::paintEvent: composition is modified, update everything
    rosegarden: CompositionModelImpl::clearPreviewCache
    rosegarden (sequence manager): SequenceManager::event() with user event
    rosegarden (sequence manager): SequenceManager::event(): update requested
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus()
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: segments modified by changes to trigger segments are:
    rosegarden (sequence manager): SequenceManager::checkRefreshStatus: we have 10 segments
    rosegarden (sequence manager): SequenceManager::segmentModified(0x8f6b7e0)
    rosegarden (sequence manager): CompositionMmapper::segmentModified(0x8f6b7e0) - mmapper = 0x8f77a98
    rosegarden (sequence manager): SegmentMmapper::refresh() - /var/tmp/kde-studio//segment_8f6b7e0 - m_mmappedRegion = 0xb7206000 - m_mmappedEventBuffer = 0xb7206004 - new size = 164 - old size = 84
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f6b7e0 to 164 - current size = 84
    rosegarden (sequence manager): SegmentMmapper : remapping /var/tmp/kde-studio//segment_8f6b7e0 from size 84 to size 164
    rosegarden (sequence manager): SequenceManager::segmentModified() : size changed = true
    rosegarden (sequence manager): SequenceManager::segmentModified() : DCOP-call sequencer remapSegment/var/tmp/kde-studio//segment_8f6b7e0
    rosegarden (sequence manager): SequenceManager::processAddedSegment(0x8f6b300)
    rosegarden (sequence manager): CompositionMmapper::segmentAdded(0x8f6b300)
    rosegarden (sequence manager): CompositionMmapper::mmapSegment(0x8f6b300)
    rosegarden (sequence manager): SegmentMmapper : 0x8f7f350 trying to mmap /var/tmp/kde-studio//segment_8f6b300
    rosegarden (sequence manager): SegmentMmapper::setFileSize() : setting size of /var/tmp/kde-studio//segment_8f6b300 to 164 - current size = 164
    rosegarden (sequence manager): SegmentMmapper::doMmap() - mmap size : 164 at 0xb7205000
    rosegarden (sequence manager): SegmentMmapper::init : mmap size = 164 for segment Acoustic Grand Piano (recorded)
    rosegarden (sequence manager): SequenceManager::event() with user event
    rosegarden: Tempo change: tempo 120 at 0:1:0:0
    rosegarden: Tempo change: tempo 120 at 0:1:0:0

     
  • Chris Cannam
    Chris Cannam
    2007-10-11

    Logged In: YES
    user_id=13489
    Originator: YES

    OK, I'm getting to the bottom of this. RosegardenGUIDoc::stopRecordingMidi pulls the first recording segment out of the recording segment map and then notation-quantizes it (calculating notation timings, that is, not changing the MIDI timings). The EventQuantizeCommand that does this work has explicit rgapp->refreshGUI calls in it, to update progress in case it takes a long time, and when one of these happen a sub-event-loop is entered. If, during that sub-event-loop, the RosegardenGUIApp's playTimer is fired, it will notice that the sequence manager's status is still RECORDING, and call back on the document's updateRecordingMidiSegment. Because there is no recording segment in the recording segment map for the relevant instrument, the document will create one and add it -- and so the loop will never end, as stopRecordingMidi will return to its work only to discover that there is another new segment to deal with and the same thing will happen again.

    Why does this happen only on punch-out? Because we already have a fix in place, of sorts, for the Stop case. SequenceManager::stop() sets m_transportStatus = STOPPED before it calls doc->stopRecordingMidi, so the app function called in the sub-loop won't try to update the recording segment. But that doesn't happen on punch out, which is handled by SequenceManager::record().

    So, we can and should fix up SequenceManager::record() so as to set the recording status first as well. But that's still rather a fragile fix. It would be far better not to get caught up in recording-related callbacks during the sub-loop. It might be better not to have a sub-loop at all, but I guess we'd better assume there are times when the notation calculation is slow enough to merit it.

     
  • Chris Cannam
    Chris Cannam
    2007-10-11

    Logged In: YES
    user_id=13489
    Originator: YES

    Hm, I was thinking we could avoid doing recording-related things in the sub-loop by stopping the play timer (which is what invokes those things) at an earlier point. But of course we can't stop the play timer because we're still playing, just not recording. Hm.

    Going to test the "fragile" fix now.

     
  • Chris Cannam
    Chris Cannam
    2007-10-11

    Logged In: YES
    user_id=13489
    Originator: YES

    Fixed in SVN (rev 8307)

     
  • Logged In: YES
    user_id=1312539
    Originator: NO

    This Tracker item was closed automatically by the system. It was
    previously set to a Pending status, and the original submitter
    did not respond within 14 days (the time period specified by
    the administrator of this Tracker).