VirtualBox

Changeset 20752 in vbox for trunk


Ignore:
Timestamp:
Jun 21, 2009 10:14:58 PM (15 years ago)
Author:
vboxsync
Message:

TMTimerSet: stats and quick optimization.

Location:
trunk
Files:
4 edited

Legend:

Unmodified
Added
Removed

  • trunk/include/VBox/vm.h

    r20750 r20752  
    926926        struct TM   s;
    927927#endif
    928         char        padding[2048];      /* multiple of 32 */
     928        char        padding[2112];      /* multiple of 32 */
    929929    } tm;
    930930

  • trunk/src/VBox/VMM/TM.cpp

    r20750 r20752  
    575575    STAM_REG(pVM, &pVM->tm.s.StatScheduleSetFF,                       STAMTYPE_COUNTER, "/TM/ScheduleSetFF",                   STAMUNIT_OCCURENCES, "The number of times the timer FF was set instead of doing scheduling.");
    576576
    577     STAM_REG(pVM, &pVM->tm.s.StatTimerSetR3,                          STAMTYPE_PROFILE, "/TM/TimerSetR3",                  STAMUNIT_TICKS_PER_CALL, "Profiling TMTimerSet calls made in ring-3.");
    578     STAM_REG(pVM, &pVM->tm.s.StatTimerSetRZ,                          STAMTYPE_PROFILE, "/TM/TimerSetRZ",                  STAMUNIT_TICKS_PER_CALL, "Profiling TMTimerSet calls made in ring-0 / RC.");
     577    STAM_REG(pVM, &pVM->tm.s.StatTimerSet,                            STAMTYPE_COUNTER, "/TM/TimerSet",                        STAMUNIT_OCCURENCES, "Calls");
     578    STAM_REG(pVM, &pVM->tm.s.StatTimerSetOpt,                         STAMTYPE_COUNTER, "/TM/TimerSet/Opt",                    STAMUNIT_OCCURENCES, "Optimized path taken.");
     579    STAM_REG(pVM, &pVM->tm.s.StatTimerSetR3,                          STAMTYPE_PROFILE, "/TM/TimerSet/R3",                 STAMUNIT_TICKS_PER_CALL, "Profiling TMTimerSet calls made in ring-3.");
     580    STAM_REG(pVM, &pVM->tm.s.StatTimerSetRZ,                          STAMTYPE_PROFILE, "/TM/TimerSet/RZ",                 STAMUNIT_TICKS_PER_CALL, "Profiling TMTimerSet calls made in ring-0 / RC.");
     581    STAM_REG(pVM, &pVM->tm.s.StatTimerSetStActive,                    STAMTYPE_COUNTER, "/TM/TimerSet/StActive",               STAMUNIT_OCCURENCES, "ACTIVE");
     582    STAM_REG(pVM, &pVM->tm.s.StatTimerSetStExpDeliver,                STAMTYPE_COUNTER, "/TM/TimerSet/StExpDeliver",           STAMUNIT_OCCURENCES, "EXPIRED_DELIVER");
     583    STAM_REG(pVM, &pVM->tm.s.StatTimerSetStOther,                     STAMTYPE_COUNTER, "/TM/TimerSet/StOther",                STAMUNIT_OCCURENCES, "Other states");
     584    STAM_REG(pVM, &pVM->tm.s.StatTimerSetStPendStop,                  STAMTYPE_COUNTER, "/TM/TimerSet/StPendStop",             STAMUNIT_OCCURENCES, "PENDING_STOP");
     585    STAM_REG(pVM, &pVM->tm.s.StatTimerSetStPendStopSched,             STAMTYPE_COUNTER, "/TM/TimerSet/StPendStopSched",        STAMUNIT_OCCURENCES, "PENDING_STOP_SCHEDULE");
     586    STAM_REG(pVM, &pVM->tm.s.StatTimerSetStPendSched,                 STAMTYPE_COUNTER, "/TM/TimerSet/StPendSched",            STAMUNIT_OCCURENCES, "PENDING_SCHEDULE");
     587    STAM_REG(pVM, &pVM->tm.s.StatTimerSetStPendResched,               STAMTYPE_COUNTER, "/TM/TimerSet/StPendResched",          STAMUNIT_OCCURENCES, "PENDING_RESCHEDULE");
     588    STAM_REG(pVM, &pVM->tm.s.StatTimerSetStStopped,                   STAMTYPE_COUNTER, "/TM/TimerSet/StStopped",              STAMUNIT_OCCURENCES, "STOPPED");
    579589
    580590    STAM_REG(pVM, &pVM->tm.s.StatTimerSetRelative,                    STAMTYPE_COUNTER, "/TM/TimerSetRelative",                STAMUNIT_OCCURENCES, "Calls");
     591    STAM_REG(pVM, &pVM->tm.s.StatTimerSetRelativeOpt,                 STAMTYPE_COUNTER, "/TM/TimerSetRelative/Opt",            STAMUNIT_OCCURENCES, "Optimized path taken.");
    581592    STAM_REG(pVM, &pVM->tm.s.StatTimerSetRelativeR3,                  STAMTYPE_PROFILE, "/TM/TimerSetRelative/R3",         STAMUNIT_TICKS_PER_CALL, "Profiling TMTimerSetRelative calls made in ring-3.");
    582593    STAM_REG(pVM, &pVM->tm.s.StatTimerSetRelativeRZ,                  STAMTYPE_PROFILE, "/TM/TimerSetRelative/RZ",         STAMUNIT_TICKS_PER_CALL, "Profiling TMTimerSetReltaive calls made in ring-0 / RC.");
    583594    STAM_REG(pVM, &pVM->tm.s.StatTimerSetRelativeRacyVirtSync,        STAMTYPE_COUNTER, "/TM/TimerSetRelative/RacyVirtSync",   STAMUNIT_OCCURENCES, "Potentially racy virtual sync timer update.");
    584     STAM_REG(pVM, &pVM->tm.s.StatTimerSetRelativeOpt,                 STAMTYPE_COUNTER, "/TM/TimerSetRelative/Opt",            STAMUNIT_OCCURENCES, "Optimized path taken.");
    585595    STAM_REG(pVM, &pVM->tm.s.StatTimerSetRelativeStActive,            STAMTYPE_COUNTER, "/TM/TimerSetRelative/StActive",       STAMUNIT_OCCURENCES, "ACTIVE");
    586596    STAM_REG(pVM, &pVM->tm.s.StatTimerSetRelativeStExpDeliver,        STAMTYPE_COUNTER, "/TM/TimerSetRelative/StExpDeliver",   STAMUNIT_OCCURENCES, "EXPIRED_DELIVER");

  • trunk/src/VBox/VMM/TMInternal.h

    r20750 r20752  
    482482    /** TMTimerSet
    483483     * @{ */
     484    STAMCOUNTER                 StatTimerSet;
     485    STAMCOUNTER                 StatTimerSetOpt;
    484486    STAMPROFILE                 StatTimerSetRZ;
    485487    STAMPROFILE                 StatTimerSetR3;
     488    STAMCOUNTER                 StatTimerSetStStopped;
     489    STAMCOUNTER                 StatTimerSetStExpDeliver;
     490    STAMCOUNTER                 StatTimerSetStActive;
     491    STAMCOUNTER                 StatTimerSetStPendStop;
     492    STAMCOUNTER                 StatTimerSetStPendStopSched;
     493    STAMCOUNTER                 StatTimerSetStPendSched;
     494    STAMCOUNTER                 StatTimerSetStPendResched;
     495    STAMCOUNTER                 StatTimerSetStOther;
    486496    /** @} */
    487497    /** TMTimerSetRelative

  • trunk/src/VBox/VMM/VMMAll/TMAll.cpp

    r20751 r20752  
    790790
    791791/**
     792 * Optimized TMTimerSet code path for starting an inactive timer.
     793 *
     794 * @returns VBox status code.
     795 *
     796 * @param   pVM             The VM handle.
     797 * @param   pTimer          The timer handle.
     798 * @param   u64Expire       The new expire time.
     799 */
     800static int tmTimerSetOptimizedStart(PVM pVM, PTMTIMER pTimer, uint64_t u64Expire)
     801{
     802    Assert(!pTimer->offPrev);
     803    Assert(!pTimer->offNext);
     804    Assert(pTimer->enmState == TMTIMERSTATE_ACTIVE);
     805
     806    /*
     807     * Calculate and set the expiration time.
     808     */
     809    pTimer->u64Expire = u64Expire;
     810    Log2(("tmTimerSetOptimizedStart: %p:{.pszDesc='%s', .u64Expire=%'RU64}\n", pTimer, R3STRING(pTimer->pszDesc), u64Expire));
     811
     812    /*
     813     * Link the timer into the active list.
     814     */
     815    TMCLOCK const enmClock = pTimer->enmClock;
     816    tmTimerActiveLink(&pVM->tm.s.CTX_SUFF(paTimerQueues)[enmClock], pTimer, u64Expire);
     817
     818    STAM_COUNTER_INC(&pVM->tm.s.StatTimerSetOpt);
     819    tmUnlock(pVM);
     820    return VINF_SUCCESS;
     821}
     822
     823
     824
     825
     826
     827/**
    792828 * Arm a timer with a (new) expire time.
    793829 *
    … …  
    798834VMMDECL(int) TMTimerSet(PTMTIMER pTimer, uint64_t u64Expire)
    799835{
    800     STAM_PROFILE_START(&pTimer->CTX_SUFF(pVM)->tm.s.CTX_SUFF_Z(StatTimerSet), a);
     836    PVM pVM = pTimer->CTX_SUFF(pVM);
     837    STAM_PROFILE_START(&pVM->tm.s.CTX_SUFF_Z(StatTimerSet), a);
    801838    TMTIMER_ASSERT_CRITSECT(pTimer);
    802839
    803     /** @todo find the most frequently used paths and make them skip tmSchedule and tmTimerTryWithLink. */
     840#ifdef VBOX_WITH_STATISTICS
     841    /* Gather optimization info. */
     842    STAM_COUNTER_INC(&pVM->tm.s.StatTimerSet);
     843    TMTIMERSTATE enmOrgState = pTimer->enmState;
     844    switch (enmOrgState)
     845    {
     846        case TMTIMERSTATE_STOPPED:                  STAM_COUNTER_INC(&pVM->tm.s.StatTimerSetStStopped); break;
     847        case TMTIMERSTATE_EXPIRED_DELIVER:          STAM_COUNTER_INC(&pVM->tm.s.StatTimerSetStExpDeliver); break;
     848        case TMTIMERSTATE_ACTIVE:                   STAM_COUNTER_INC(&pVM->tm.s.StatTimerSetStActive); break;
     849        case TMTIMERSTATE_PENDING_STOP:             STAM_COUNTER_INC(&pVM->tm.s.StatTimerSetStPendStop); break;
     850        case TMTIMERSTATE_PENDING_STOP_SCHEDULE:    STAM_COUNTER_INC(&pVM->tm.s.StatTimerSetStPendStopSched); break;
     851        case TMTIMERSTATE_PENDING_SCHEDULE:         STAM_COUNTER_INC(&pVM->tm.s.StatTimerSetStPendSched); break;
     852        case TMTIMERSTATE_PENDING_RESCHEDULE:       STAM_COUNTER_INC(&pVM->tm.s.StatTimerSetStPendResched); break;
     853        default:                                    STAM_COUNTER_INC(&pVM->tm.s.StatTimerSetStOther); break;
     854    }
     855#endif
     856
     857    /*
     858     * The most common case is setting the timer again during the callback.
     859     * The second most common case is starting a timer at some other time.
     860     */
     861#if 1
     862    TMTIMERSTATE enmState = pTimer->enmState;
     863    if (    enmState == TMTIMERSTATE_EXPIRED_DELIVER
     864        ||  (   enmState == TMTIMERSTATE_STOPPED
     865             && pTimer->pCritSect))
     866    {
     867        /* Try take the TM lock and check the state again. */
     868        if (RT_SUCCESS_NP(tmTryLock(pVM)))
     869        {
     870            if (RT_LIKELY(tmTimerTry(pTimer, TMTIMERSTATE_ACTIVE, enmState)))
     871            {
     872                tmTimerSetOptimizedStart(pVM, pTimer, u64Expire);
     873                STAM_PROFILE_STOP(&pTimer->CTX_SUFF(pVM)->tm.s.CTX_SUFF_Z(StatTimerSetRelative), a);
     874                return VINF_SUCCESS;
     875            }
     876            tmUnlock(pVM);
     877        }
     878    }
     879#endif
     880
     881    /*
     882     * Unoptimized code path.
     883     */
    804884    int cRetries = 1000;
    805885    do
    … …  
    820900                    Assert(!pTimer->offNext);
    821901                    AssertMsg(      pTimer->enmClock != TMCLOCK_VIRTUAL_SYNC
    822                               ||    pTimer->CTX_SUFF(pVM)->tm.s.fVirtualSyncTicking
    823                               ||    u64Expire >= pTimer->CTX_SUFF(pVM)->tm.s.u64VirtualSync,
    824                               ("%'RU64 < %'RU64 %s\n", u64Expire, pTimer->CTX_SUFF(pVM)->tm.s.u64VirtualSync, R3STRING(pTimer->pszDesc)));
     902                              ||    pVM->tm.s.fVirtualSyncTicking
     903                              ||    u64Expire >= pVM->tm.s.u64VirtualSync,
     904                              ("%'RU64 < %'RU64 %s\n", u64Expire, pVM->tm.s.u64VirtualSync, R3STRING(pTimer->pszDesc)));
    825905                    pTimer->u64Expire = u64Expire;
    826906                    TM_SET_STATE(pTimer, TMTIMERSTATE_PENDING_SCHEDULE);
    827907                    tmSchedule(pTimer);
    828                     STAM_PROFILE_STOP(&pTimer->CTX_SUFF(pVM)->tm.s.CTX_SUFF_Z(StatTimerSet), a);
     908                    STAM_PROFILE_STOP(&pVM->tm.s.CTX_SUFF_Z(StatTimerSet), a);
    829909                    return VINF_SUCCESS;
    830910                }
    … …  
    838918                    TM_SET_STATE(pTimer, TMTIMERSTATE_PENDING_SCHEDULE);
    839919                    tmSchedule(pTimer);
    840                     STAM_PROFILE_STOP(&pTimer->CTX_SUFF(pVM)->tm.s.CTX_SUFF_Z(StatTimerSet), a);
     920                    STAM_PROFILE_STOP(&pVM->tm.s.CTX_SUFF_Z(StatTimerSet), a);
    841921                    return VINF_SUCCESS;
    842922                }
    … …  
    850930                    TM_SET_STATE(pTimer, TMTIMERSTATE_PENDING_RESCHEDULE);
    851931                    tmSchedule(pTimer);
    852                     STAM_PROFILE_STOP(&pTimer->CTX_SUFF(pVM)->tm.s.CTX_SUFF_Z(StatTimerSet), a);
     932                    STAM_PROFILE_STOP(&pVM->tm.s.CTX_SUFF_Z(StatTimerSet), a);
    853933                    return VINF_SUCCESS;
    854934                }
    … …  
    862942                    TM_SET_STATE(pTimer, TMTIMERSTATE_PENDING_RESCHEDULE);
    863943                    tmSchedule(pTimer);
    864                     STAM_PROFILE_STOP(&pTimer->CTX_SUFF(pVM)->tm.s.CTX_SUFF_Z(StatTimerSet), a);
     944                    STAM_PROFILE_STOP(&pVM->tm.s.CTX_SUFF_Z(StatTimerSet), a);
    865945                    return VINF_SUCCESS;
    866946                }
    … …  
    893973
    894974    AssertMsgFailed(("Failed waiting for stable state. state=%d (%s)\n", pTimer->enmState, R3STRING(pTimer->pszDesc)));
    895     STAM_PROFILE_STOP(&pTimer->CTX_SUFF(pVM)->tm.s.CTX_SUFF_Z(StatTimerSet), a);
     975    STAM_PROFILE_STOP(&pVM->tm.s.CTX_SUFF_Z(StatTimerSet), a);
    896976    return VERR_INTERNAL_ERROR;
    897977}
    … …  
    10121092     *       get the innermost locks.
    10131093     */
    1014     bool fOwnTMLock = RT_SUCCESS(tmTryLock(pVM));
     1094    bool fOwnTMLock = RT_SUCCESS_NP(tmTryLock(pVM));
    10151095#if 1
    10161096    if (    fOwnTMLock
    … …  
    11681248        if (!fOwnTMLock)
    11691249        {
    1170             fOwnTMLock = RT_SUCCESS(tmTryLock(pVM));
     1250            fOwnTMLock = RT_SUCCESS_NP(tmTryLock(pVM));
    11711251            if (    !fOwnTMLock
    11721252                &&  enmClock == TMCLOCK_VIRTUAL_SYNC
    11731253                &&  !fOwnVirtSyncLock)
    1174                 fOwnVirtSyncLock = RT_SUCCESS(tmVirtualSyncTryLock(pVM));
     1254                fOwnVirtSyncLock = RT_SUCCESS_NP(tmVirtualSyncTryLock(pVM));
    11751255        }
    11761256
Note: See TracChangeset for help on using the changeset viewer.

© 2024 Oracle Support Privacy / Do Not Sell My Info Terms of Use Trademark Policy Automated Access Etiquette