> On Nov 12, 2015, at 9:05 AM, Michael Zimmermann <[email protected]> > wrote: > > thx, this perfectly explains my situation(that EDK2 shell stops while > printing sth. like the map or waiting for this 5s startup.nsh timeout). > > So this means that processing the event queue is caused by any API call which > never returns to the DXE phase for some reason. >
You should also check your code looking for TPL violations. Calling EFI Services at to high a TPL can lead to undefined behavior. If you look at the UEFI 2.5 spec, Section 6.1 Event, Timer, and Task Priority Services Table 23 lists TPL Restrictions. You can check that your code is not violating any of these restrictions. The natural reaction for some one having performance issues is to cheat and try to elevate their TPL. ... The class of bugs created by calling EFI Services at to hight a TPL are usually reentrancy related. Basically the locks in the DXE Core raise TPL to protect critical sections, like the protocol data base or event queue. Calling at an illegal TPL can cause corruption of some of these structures, and thus undefined behavior. Another possibility is an event TPL deadlock. When your event runs at a TPL only events of a higher TPL can run. Your event is blocking code at <= current TPL from running. So if your event is waiting on something to complete that needs to run at <= the current TPL that code is starved and will never get run. The TPL Restriction table is the guide here also. For example if you driver implements Block IO it can be called at TPL <= TPL_CALLBACK, so if your driver has an event that needs to complete to make forward progress it needs to run at TPL_NOTIFY. Since you are producing GOP, there is going to be system code that implements Simple Text Output on top of GOP so you inherit those TPL restrictions. > Is there a special way to debug the event system or do I have to put DEBUG > calls all over the place? > Actually putting DEBUG prints all over the place can make it worse as you can increase the amount of time spent processing events. I'm not sure if you have a debugger, but if you do.... 1) I'd break in a few times during the hang to try and get an idea of which event is taking all the time from the back trace 2) Pay attention to the TPL when you break in, dump gEfiCurrentTpl 3) You can walk the gEventQueue[] LIST_ENTRY to see what events are active. >= your current TPL. 4) As I mentioned I have lldb scripts to dump queues so you can figure out the high frequency timer functions and inspect that code. If you don't have a debugger... 1) Add DEBUG print to CoreCreateEventInternal() and print out info about timer events that get created. Then you can look at the timer event functions. 2) CoreDispatchEventNotifies() calls the event notify functions. Event->NotifyFunction (Event, Event->NotifyContext); You can use the TimerLib to try and figure out what event is taking al the time. You can DEBUG print the slowest function, and maybe only do it every Nth time so you don't do it 1,000 times a second. You could also add code to figure out if the function is running longer than (or some large percentage of) its period. Caveat Emptor .... Assume it is your event and figure out if you are doing something slow at an elevated TPL, calling a service at too hight a TPL., or have TPL related deadlock based on the TPL restrictions. Thanks, Andrew Fish PS Sorry if this is more detail than you needed, but I figured other folks might find this useful. > On Thu, Nov 12, 2015 at 5:44 PM, Andrew Fish <[email protected] > <mailto:[email protected]>> wrote: > > > On Nov 12, 2015, at 3:28 AM, Andrew Fish <[email protected] > > <mailto:[email protected]>> wrote: > > > >> > >> On Nov 12, 2015, at 3:22 AM, Andrew Fish <[email protected] > >> <mailto:[email protected]>> wrote: > >> > >> > >>> On Nov 12, 2015, at 12:49 AM, Michael Zimmermann > >>> <[email protected] <mailto:[email protected]>> wrote: > >>> > >>> Stall was just an example, I can also use DEBUG. My timer interval is > >>> 100ms(I converted it from the 100ns unit). > >>> > >>> What I meant with "thread mode code" is the "normal" non IRQ context code > >>> running on the CPU. That means that there are actually two contexts in > >>> EDK2, the exception(i.e. IRQ's like the Timer/Watchdog) and the normal > >>> mode > >>> all code is running in. > >>> > >> > >> OK thanks that helps. The timer ISR runs in interrupt context, and from an > >> ARM point of view EFI is running the ARM "Thread mode". The ISR context > >> is an implementation detail and not really defined by the specification. > >> > >> I'd also point out the Events dispatch independent of the interrupt > >> context. gBS->RestoreTpl() can cause events to dispatch. For example a lot > >> of the EFI Protocol services have locks that raise TPL to prevent > >> recursion. When these locks are released and the TPL is restored events > >> are dispatched. So just calling EFI services can cause events to run. So > >> conceptually you can ignore the interrupt context, as that is used to > >> implement the timer tick. Every thing else is an event that runs in the > >> main EFI context. > >> > >> https://github.com/tianocore/edk2/blob/master/MdeModulePkg/Core/Dxe/Event/Tpl.c#L126 > >> > >> <https://github.com/tianocore/edk2/blob/master/MdeModulePkg/Core/Dxe/Event/Tpl.c#L126> > >> > > > > As Kinney pointed out the events are cooperative and there is no scheduler, > > so if you are getting stuck some chunk of code is running too long at an > > elevated TPL. You may need to performance profile to figure out the bad > > code. > > > > The events are managed by queues in the DXE Core. The events are described by > the IEVENT data structure and linked into queues based on state. The state > transition to the event is calling a C function stored in the IEVENT. The > event must return, or call an EFI service, to give control back to the DXE > Core. > > https://github.com/tianocore/edk2/blob/master/MdeModulePkg/Core/Dxe/Event/Event.c > > <https://github.com/tianocore/edk2/blob/master/MdeModulePkg/Core/Dxe/Event/Event.c> > > /// > /// gEventQueueLock - Protects the event queues > /// > EFI_LOCK gEventQueueLock = EFI_INITIALIZE_LOCK_VARIABLE (TPL_HIGH_LEVEL); > > /// > /// gEventQueue - A list of event's to notify for each priority level > /// > LIST_ENTRY gEventQueue[TPL_HIGH_LEVEL + 1]; > > /// > /// gEventPending - A bitmask of the EventQueues that are pending > /// > UINTN gEventPending = 0; > > /// > /// gEventSignalQueue - A list of events to signal based on EventGroup type > /// > LIST_ENTRY gEventSignalQueue = INITIALIZE_LIST_HEAD_VARIABLE > (gEventSignalQueue); > > It is possible to write a debugger script to dump out the info about the > events if you have source level debug available for the DXE Core. > > Thanks, > > Andrew Fish > > > Thanks, > > > > Andrew Fish > > > > > >> Thanks, > >> > >> Andrew Fish > >> > >> > >>> On Thu, Nov 12, 2015 at 9:27 AM, Andrew Fish <[email protected] > >>> <mailto:[email protected]>> wrote: > >>> > >>>> > >>>>> On Nov 11, 2015, at 11:51 PM, Michael Zimmermann < > >>>> [email protected] <mailto:[email protected]>> wrote: > >>>>> > >>>>> I've started investigating in the timer event problem and I think I have > >>>>> some weird problem with my platform drivers(I hope, so it's not a EDK2 > >>>> bug). > >>>>> > >>>>> If I create a timer that runs every 100ms which does nothing but a > >>>>> stall(1), the thread mode code stops after some random time(usually in > >>>> edk2 > >>>>> shell so I guess it's a race condition which needs some cpu load). > >>>>> > >>>> > >>>> Michael, > >>>> > >>>> Watch out as Stall() is Microseconds, and SetTimer() is 100ns I've seen > >>>> bugs like that before in code. > >>>> > >>>>> When threadmode code is stopped the timer continues getting called and > >>>> even > >>>>> if I stop the timer afterwards(with CloseEvent) it keeps being stopped. > >>>>> > >>>>> Is there a way to get the threadmode context from inside a timer > >>>> callback? > >>>>> This way I could read the PC to check what's going on. > >>>>> > >>>> > >>>> There are no threads. EFI is an event model. If your code is running you > >>>> are blocking every one else's forward progress. Only code running at a > >>>> higher TPL can preempt. So when your event is running it is blocking the > >>>> main flow and any event trying to run at <= TPL of your event from making > >>>> forward progress. gBS->Stall() does not yield, it is no different than > >>>> running code. > >>>> > >>>> So there is only one context, you can print it out any time you want. > >>>> > >>>> Thanks, > >>>> > >>>> Andrew Fish > >>>> > >>>> PS When folks yell at us for not having threads in EFI we point them at: > >>>> https://web.stanford.edu/~ouster/cgi-bin/papers/threads.pdf > >>>> <https://web.stanford.edu/~ouster/cgi-bin/papers/threads.pdf> > >>>> > >>>> > >>>>> Michael > >>>>> > >>>>> On Wed, Nov 11, 2015 at 8:10 PM, Kinney, Michael D < > >>>>> [email protected] <mailto:[email protected]>> wrote: > >>>>> > >>>>>> Michael, > >>>>>> > >>>>>> A periodic event timer at 30 times a second should not cause pauses > >>>>>> forever, unless the action you are performing in the event notification > >>>>>> function takes more than 1/30 of a second to complete. You should be > >>>> able > >>>>>> to just add a periodic event handler that does nothing, so you can > >>>> measure > >>>>>> what the overhead is. > >>>>>> > >>>>>> Another option is to use the performance counter in the TimerLib each > >>>> time > >>>>>> a Blt() is called (GetPerformanceCounterProperties() and > >>>>>> GetPerformanceCounter()). When Blt() is called frequently, the amount > >>>> of > >>>>>> time since last vsync will have elapsed, and you can go the vsync > >>>>>> action > >>>>>> within the Blt() call. If you also set a one shot timer event, so if > >>>> the > >>>>>> last call to Blt() did not do a vsync and there are no more Blt() > >>>>>> calls, > >>>>>> 1/30th of a second later, the vsync action can be done. Every time > >>>> Blt() > >>>>>> is called, the one shot timer can be re-armed. This way, the one shot > >>>>>> timer event is not actually executed very often. > >>>>>> > >>>>>> Mike > >>>>>> > >>>>>>> -----Original Message----- > >>>>>>> From: edk2-devel [mailto:[email protected] > >>>>>>> <mailto:[email protected]>] On Behalf Of > >>>>>> Michael Zimmermann > >>>>>>> Sent: Wednesday, November 11, 2015 12:32 AM > >>>>>>> To: [email protected] <mailto:[email protected]> > >>>>>>> Subject: [edk2] EFI GOP with manual vsync trigger > >>>>>>> > >>>>>>> Hi, > >>>>>>> > >>>>>>> my Graphics HW uses a manual vsync trigger. That means that after > >>>> drawing > >>>>>>> to the framebuffer I need to manually trigger vsync(you can compare it > >>>> to > >>>>>>> switching between double buffers). > >>>>>>> > >>>>>>> The problem is that UEFI's GraphicsOutputProtocol(GOP) doesn't take > >>>> care > >>>>>> of > >>>>>>> HW that needs a flush. > >>>>>>> While issuing the trigger after every Blt Operation works, this > >>>> obviously > >>>>>>> causes extremely slow rendering for applications like the Shell which > >>>> call > >>>>>>> Blt very often(like for every character). > >>>>>>> > >>>>>>> Also I can't use a timer to set the trigger(like 30times a second) > >>>> because > >>>>>>> it takes too much time and the Timer Interrupt ends up consuming too > >>>> much > >>>>>>> time and the "normal" code gets paused forever. > >>>>>>> > >>>>>>> Do you have any other ideas how to handle this? > >>>>>>> > >>>>>>> Thx > >>>>>>> Michael > >>>>>>> _______________________________________________ > >>>>>>> edk2-devel mailing list > >>>>>>> [email protected] <mailto:[email protected]> > >>>>>>> https://lists.01.org/mailman/listinfo/edk2-devel > >>>>>>> <https://lists.01.org/mailman/listinfo/edk2-devel> > >>>>>> > >>>>> _______________________________________________ > >>>>> edk2-devel mailing list > >>>>> [email protected] <mailto:[email protected]> > >>>>> https://lists.01.org/mailman/listinfo/edk2-devel > >>>>> <https://lists.01.org/mailman/listinfo/edk2-devel> > >>>> > >>>> > >>> _______________________________________________ > >>> edk2-devel mailing list > >>> [email protected] <mailto:[email protected]> > >>> https://lists.01.org/mailman/listinfo/edk2-devel > >>> <https://lists.01.org/mailman/listinfo/edk2-devel> > >> > >> _______________________________________________ > >> edk2-devel mailing list > >> [email protected] <mailto:[email protected]> > >> https://lists.01.org/mailman/listinfo/edk2-devel > >> <https://lists.01.org/mailman/listinfo/edk2-devel> > > _______________________________________________ edk2-devel mailing list [email protected] https://lists.01.org/mailman/listinfo/edk2-devel
