> Could you please install oprofile and try to find out where your CPU is > spending it's time?
Hi, Small problem is that I just have set up everything in a P1 box, which does not support the real CPU counter oprofile likes to use, so it runs in RTC mode, which has a fairly low sample count. However, it does show some clear hot spots, note that the RTC counter does not update inside an interrupt (according to the oprofile manual). I have done several runs, for different amounts of time and the results are consistent. Loading HEAD drivers, starting vdr 1.1.14, hitting "record" (channel is tuned and all is good), gives: (only pasting the relevant parts, full output is quite large) VMA Samples %-time symbol name dvb-ttpci.o: ... 00004a70 2 0.00623305 arm_thread 000097e0 2 0.00623305 StartHWFilter 00009e90 2 0.00623305 dvb_stop_feed 0000b620 2 0.00623305 av7110_before_after_tune 0000a010 9 0.0280487 av7110_diseqc_ioctl 00000f20 16 0.0498644 master_xfer 000001f0 31 0.0966123 i2c_reset 00000dd0 57 0.177642 do_master_xfer 00006320 69 0.21504 OutCommand 00000370 76 0.236856 i2c_write_out 00000470 87 0.271138 clean_up 00000030 99 0.308536 i2c_busy_rise_and_fall 00000570 124 0.386449 prepare 00000000 245 0.763549 i2c_status_check 0000c850 314 0.978589 DvbDmxFilterCallback 000066c0 440 1.37127 CommandRequest 0000c5c0 1356 4.22601 __constant_memcpy 000047d0 1550 4.83062 debiwrite 00005710 2053 6.39823 debiirq 00005bc0 3747 11.6776 gpioirq 00004840 5288 16.4802 debiread 00004750 16518 51.4788 wait_for_debi_done dvb-core.o: ... 00000940 1 0.00407963 DmxDevFilterStart 000010c0 1 0.00407963 dvb_demux_do_ioctl 00001d20 1 0.00407963 dmx_pid_set 000021e0 1 0.00407963 dmx_section_feed_allocate_filter 00008afc 1 0.00407963 .text.lock.dvb_frontend 00008f40 1 0.00407963 dvb_generic_ioctl 00000cc0 2 0.00815927 dvb_demux_open 000072b0 2 0.00815927 dvb_frontend_add_event 00007560 2 0.00815927 dvb_frontend_set_parameters 00007b80 2 0.00815927 dvb_frontend_ioctl 00008e30 2 0.00815927 generic_usercopy 00001640 3 0.0122389 __constant_memcpy 00002360 3 0.0122389 prepare_secfilters 000070b0 3 0.0122389 dvb_bend_frequency 00008970 4 0.0163185 __constant_memcpy 00007790 8 0.0326371 dvb_frontend_recover 00007890 8 0.0326371 dvb_frontend_thread 000076f0 9 0.0367167 update_delay 00007030 14 0.0571149 dvb_frontend_internal_ioctl 00007840 17 0.0693538 dvb_frontend_is_exiting 00000640 154 0.628264 DmxDevSectionCallback 00001070 155 0.632343 dvb_demux_read 00000f30 191 0.77921 DmxDevReadSec 00001350 233 0.950555 dvb_dvr_poll 00001220 949 3.87157 dvb_demux_poll 00001c10 999 4.07555 DvbDmxSWFilterPackets 000004e0 1120 4.56919 dvb_dvr_read 00000000 1965 8.01648 DmxDevBufferRead 00000710 2150 8.77121 DmxDevTSCallback 00001ae0 2526 10.3052 DvbDmxSWFilterPacket 00001740 13985 57.0537 DmxDevBufferWrite vdr binary: ... 0809a9e0 35 0.079021 cMutexLock::~cMutexLock() 080942b0 42 0.0948253 cKbdRemote::Action() 08093070 43 0.097083 cIndexFile::Write(unsigned char, unsigned char, int) 08074ea0 45 0.101598 cEIT::cEIT(unsigned char*, int, cSchedules*) 0809c7b0 60 0.135465 readline(_IO_FILE*) 08073c30 72 0.162558 cEventInfo::Read(_IO_FILE*, cSchedule*) 0809a980 73 0.164815 cMutexLock::cMutexLock(cMutex*) 0809aa10 76 0.171589 cMutexLock::Lock(cMutex*) 080739c0 127 0.286733 cEventInfo::GetTime() const 0809d960 127 0.286733 cPoller::Poll(int) 08090400 151 0.340919 cRecorder::NextFile() 0809c6a0 177 0.399621 safe_read(int, void*, unsigned) 080952a0 208 0.469611 cRemux::GetPid(unsigned char const*) 080747c0 218 0.492188 cSchedule::GetEvent(unsigned short, long) const 080739e0 225 0.507992 cEventInfo::GetEventID() const 08094730 294 0.663777 cTS2PES::send_ipack() 0809c700 359 0.81053 safe_write(int, void const*, unsigned) 0809a3b0 386 0.871489 cCondVar::Broadcast() 08094670 454 1.02502 cTS2PES::store(unsigned char*, int) 08096060 606 1.36819 cRingBufferLinear::Get(unsigned char*, int) 0809d8d0 617 1.39303 cPoller::Add(int, bool) 08094cd0 629 1.42012 cTS2PES::ts_to_pes(unsigned char const*) 0806fa30 722 1.63009 cDvbDevice::GetTSPacket(unsigned char*&) 08095b80 751 1.69557 cRingBuffer::EnableGet() 08075560 791 1.78588 cSIProcessor::Action() 0809d8a0 795 1.79491 cPoller::cPoller(int, bool) 0806c540 813 1.83555 cTSBuffer::Get() 080904f0 863 1.94843 cRecorder::Action() 0809a4c0 909 2.05229 cMutex::Unlock() 0808fb80 1306 2.94861 cReceiver::WantsPid(int) 080947d0 1849 4.17457 cTS2PES::write_ipack(unsigned char const*, int) 0806c410 1878 4.24004 cTSBuffer::Read() 08095390 2114 4.77287 cRemux::Process(unsigned char const*, int&, int&, unsigned char*) 08090480 2463 5.56082 cRecorder::Receive(unsigned char*, int) 0809a470 2713 6.12526 cMutex::Lock() 0806bf40 3509 7.92242 cDevice::Action() 08094880 4197 9.47575 cTS2PES::instant_repack(unsigned char const*, int) 08095ea0 4556 10.2863 cRingBufferLinear::Put(unsigned char const*, int) 08095300 8658 19.5475 cRemux::ScanVideoPacket(unsigned char const*, int, int, unsigned char&) When I use gprof with vdr, I get similar output, ScanVideoPacket tops the list, similarly high lock contention (lot of time spent waiting for a mutex lock). DmxDevBufWrite usually (99% of the time) returns 188 bytes, TS packet. Seems like an awful lot of context switches to transfer up to 1 megabyte/sec to VDR ? (though appears to be on purpose so I am sure there is a reason :) Or is this buffered already? I am not sure what to look for anymore, so any more hints are appreciated :) Thanks for pointing out oprofile btw, very nice!! Cheers, Dennis -- Info: To unsubscribe send a mail to [EMAIL PROTECTED] with "unsubscribe linux-dvb" as subject.
