B_PRIdBIGTIME
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] ", \
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] %s" prefix, \
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] %s:%d: ", \
B_PRIdBIGTIME ": %5" B_PRId32 "] %s():%d: ", system_time(), \
B_PRIdBIGTIME ": %5" B_PRId32 "] ", system_time(), DEBUG_THREAD); \
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] %s()" prefix, \
LOG_EVENT("KB_READ: %" B_PRIdBIGTIME ", %02x, %02" B_PRIx32 "\n",
TRACE(" fRepeatDelay: %" B_PRIdBIGTIME "\n", fRepeatDelay);
TRACE(" fRepeatDelay: %" B_PRIdBIGTIME "\n", fRepeatDelay);
TRACE(" fClickSpeed: %" B_PRIdBIGTIME "\n", fClickSpeed);
TRACE(" fClickSpeed: %" B_PRIdBIGTIME "\n", fClickSpeed);
"clicks: %d, timestamp %" B_PRIdBIGTIME "\n",
TRACE("New time %" B_PRIdBIGTIME "\n", newTime);
TRACE("Current time %" B_PRIdBIGTIME "\n", currentTime);
TRACE("Time diff %" B_PRIdBIGTIME "\n", diffTime);
TRACE("Set system time to %" B_PRIdBIGTIME "\n", newTime);
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] ", system_time(),\
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] %s" prefix, \
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] ", system_time(), DEBUG_THREAD); \
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] %s" prefix, system_time(), DEBUG_THREAD, \
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] %s:%d: ", system_time(), DEBUG_THREAD, \
TRACE(("tty_input_read: icanon vmin %lu, vtime %" B_PRIdBIGTIME
TRACE(("tty_input_read: AcquireReader(%" B_PRIdBIGTIME "us, %ld)\n",
dprintf("IPv4 [%" B_PRIdBIGTIME "] " format "\n", system_time() , \
dprintf("IPv4 [%" B_PRIdBIGTIME "] %p " format "\n", system_time(), \
dprintf("IPv6 [%" B_PRIdBIGTIME "] " format "\n", system_time(), ##args)
dprintf("IPv6 [%" B_PRIdBIGTIME "] %p " format "\n", system_time(), \
TRACE("starting initial retransmit timer of: %" B_PRIdBIGTIME,
out.Print("tcp:%p (%12s) %s timer set to %" B_PRIdBIGTIME, fEndpoint,
B_PRIdBIGTIME, fRetransmitTimeout);
TRACE(" RTO is now %" B_PRIdBIGTIME " (after rtt %" B_PRId32 "ms)",
B_PRIdBIGTIME ")", strerror(status), timeout);
B_PRIdBIGTIME "] %p (%12s) " format "\n", find_thread(NULL), \
TRACE(" Connect(): Connection complete: %s (timeout was %" B_PRIdBIGTIME
dprintf("TCP PROBE %" B_PRIdBIGTIME " %s %s %" B_PRIu32 " snxt %" B_PRIu32 \
B_PRIuSIZE " sqused %" B_PRIuSIZE " rto %" B_PRIdBIGTIME "\n", \
TRACE("[%" B_PRId32 "] %p->UnixFifo::Read(%p, %ld, %" B_PRIdBIGTIME ") %d\n",
TRACE("[%" B_PRId32 "] %p->UnixFifo::Write(%p, %ld, %p, %" B_PRIdBIGTIME
"idleTime %" B_PRIdBIGTIME "/%" B_PRIdBIGTIME, state, cpu,
B_PRIdBIGTIME " usec\n", fInternalLatency);
TRACE("AudioMixer: Dequeued input buffer %" B_PRIdBIGTIME
printf("AudioMixer::GetLatencyFor %" B_PRIdBIGTIME ", timesource is %"
TRACE("AudioMixer: Downstream Latency is %" B_PRIdBIGTIME " usecs\n",
TRACE("AudioMixer: buffer duration is %" B_PRIdBIGTIME " usecs\n",
TRACE("AudioMixer: Internal latency is %" B_PRIdBIGTIME " usecs\n",
TRACE("MixerCore: delaying _MixThread start, timesource is at %" B_PRIdBIGTIME "\n",
"%" B_PRIdBIGTIME "\n", start
"%" B_PRIdBIGTIME "\n", start
"%" B_PRIdBIGTIME "\n", fLastDataAvailableTime
"%" B_PRIdBIGTIME "\n", fLastDataAvailableTime
PRINT(("\tdownstream latency = %" B_PRIdBIGTIME "\n", fLatency));
PRINT(("\tbuffer-filling took %" B_PRIdBIGTIME " usec on this machine\n",
fprintf(stderr, "\tincreasing latency to %" B_PRIdBIGTIME"\n",
fprintf(stderr," <- LATE BUFFER: %" B_PRIdBIGTIME "\n", lateness);
"%" B_PRIi32 ", lateness:%" B_PRIdBIGTIME "\n",
PRINT(("MultiAudioNode::HandleSeek(t=%" B_PRIdBIGTIME ",d=%" B_PRIi32
PRINT(("id: %" B_PRIi32 ", performance_time: %" B_PRIdBIGTIME
PRINT(("MultiAudioNode::RunThread: recorded_real_time: %" B_PRIdBIGTIME
PRINT(("\tlatency = %" B_PRIdBIGTIME ", buffer duration = %" B_PRIdBIGTIME
PRINT((" internal latency = %" B_PRIdBIGTIME "\n", fInternalLatency));
PRINT(("apply configuration in: %" B_PRIdBIGTIME "\n",
TRACE("\tdownstream latency = %" B_PRIdBIGTIME "\n", fLatency);
TRACE("\tbuffer-filling took %" B_PRIdBIGTIME " usec on this machine\n",
fprintf(stderr, "\tincreasing latency to %" B_PRIdBIGTIME "\n",
fprintf(stderr," <- LATE BUFFER : %" B_PRIdBIGTIME "\n", how_early);
TRACE("OpenSoundNode::HandleSeek(t=%" B_PRIdBIGTIME ", d=%" B_PRId32 ", bd=%" B_PRId64 ")\n",
printf("TimeSourceOp op B_TIMESOURCE_SEEK, real %" B_PRIdBIGTIME ", "
"perf %" B_PRIdBIGTIME "\n", op.real_time, op.performance_time);
TRACE("id : %i, performance_time : %" B_PRIdBIGTIME ", size : %zi\n", id,
TRACE("NodeOutput::AllocateBuffers(bufferDuration = %" B_PRIdBIGTIME ", "
"latency = %" B_PRIdBIGTIME ")\n", bufferDuration, latency);
TRACE("apply configuration in : %" B_PRIdBIGTIME "µs\n", system_time() - start);
TRACE("OpenSoundNode::GetLatencyFor() - EventLatency %" B_PRIdBIGTIME ", OSS %" B_PRIdBIGTIME
TRACE(" internal latency = %" B_PRIdBIGTIME "\n", fInternalLatency);
FPRINTF(stderr, "\tdownstream latency = %" B_PRIdBIGTIME "\n", mLatency);
FPRINTF(stderr, "\tbuffer-filling took %" B_PRIdBIGTIME
FPRINTF(stderr, "\tincreasing latency to %" B_PRIdBIGTIME "\n",
PRINT(("ToneProducer::LatencyChanged(): %" B_PRIdBIGTIME "\n",
PRINT(("ToneProducer::Start(%" B_PRIdBIGTIME "): now %" B_PRIdBIGTIME "\n",
printf("ToneProducer: B_PRODUCER_STOPPED at %" B_PRIdBIGTIME "\n",
FPRINTF(stderr, "\tlatency = %" B_PRIdBIGTIME ", buffer duration = %"
B_PRIdBIGTIME "\n", mLatency, BufferDuration());
PRINTF(1, ("HandleStart(%" B_PRIdBIGTIME ")\n", performance_time));
"acquire_sem_etc() until %" B_PRIdBIGTIME "µs " \
"(in %" B_PRIdBIGTIME "µs)\n", \
PRINT(("PS: %" B_PRIdBIGTIME "\n", fProcessingLatency));
PRINTF(1, ("FrameGenerator: wait until %" B_PRIdBIGTIME ", "
fprintf(stderr, "VideoMixerNode::Start(pt=%" B_PRIdBIGTIME ")\n", performance_time);
fprintf(stderr, "VideoMixerNode::Stop(pt=%" B_PRIdBIGTIME ",<immediate>)\n",
fprintf(stderr, "VideoMixerNode::Stop(pt=%" B_PRIdBIGTIME ",<scheduled>)\n",
fprintf(stderr, "VideoMixerNode::Seek(mt=%" B_PRIdBIGTIME ",pt=%" B_PRIdBIGTIME ")\n",
fprintf(stderr, "VideoMixerNode::TimeWarp(rt=%" B_PRIdBIGTIME ",pt=%" B_PRIdBIGTIME ")\n",
fprintf(stderr, " internal latency guessed = %" B_PRIdBIGTIME "\n", fInternalLatency);
fprintf(stderr, "VideoMixerNode(BMediaEventLooper)::HandleSeek(t=%" B_PRIdBIGTIME ",d=%"
fprintf(stderr, " internal latency guessed = %" B_PRIdBIGTIME "\n", fInternalLatency);
PRINTF(1, ("HandleStart(%" B_PRIdBIGTIME ")\n", performance_time));
TRACE(" start_time: %" B_PRIdBIGTIME " or %.5fs\n", startTime,
TRACE(" duration: %" B_PRIdBIGTIME " or %.5fs\n", *duration, *duration / 1000000.0);
TRACE_SEEK(" need to seek back (%" B_PRIdBIGTIME ") (time: %.2f "
TRACE_SEEK(" found time: %" B_PRIdBIGTIME " -> %" B_PRIdBIGTIME " (%.2f)\n", *time,
"start_time: %" B_PRIdBIGTIME ")\n", fStream->index, chunkBuffer, chunkSize,
B_PRIdBIGTIME "\n", buffer->ID(), buffer->Header()->start_time);
"- offset: %" B_PRIdBIGTIME "\n", offset));
" ref('%s')->_seekStopped(%" B_PRIdBIGTIME ") failed:\n"
" ref('%s')->_start(%" B_PRIdBIGTIME ") failed:\n"
"- offset: %" B_PRIdBIGTIME "\n", offset));
" by %" B_PRIdBIGTIME "\n", -timeout));
B_PRIdBIGTIME ") failed: %s\n",
"*** NodeRef('%s')::_preroll(%" B_PRIdBIGTIME
"*** NodeRef('%s')::_preroll(%" B_PRIdBIGTIME
"NodeRef('%s')::_seek(to %" B_PRIdBIGTIME ", at %" B_PRIdBIGTIME ")\n",
"*** NodeRef('%s')::_seek(to %" B_PRIdBIGTIME ", at %"
B_PRIdBIGTIME "): BMediaRoster::SeekNode():\n"
"NodeRef('%s')::_roll(%" B_PRIdBIGTIME " to %" B_PRIdBIGTIME
", from %" B_PRIdBIGTIME ")\n"
" %" B_PRIdBIGTIME "\n", latency));
PRINT(("\treturning %" B_PRIdBIGTIME "\n", *poLatency));
PRINT(("\tdownstream latency = %" B_PRIdBIGTIME "\n", m_downstreamLatency));
PRINT(("\tprocessing latency = %" B_PRIdBIGTIME "\n", m_processingLatency));
PRINT(("\treturning %" B_PRIdBIGTIME "\n", *poLatency));
"\thowLate == %" B_PRIdBIGTIME "\n"
"\twhen == %" B_PRIdBIGTIME "\n", howLate, tpWhen));
sprintf(buf, "%-24s : realtime = %" B_PRIdBIGTIME ", perftime = %" B_PRIdBIGTIME "\n",
sprintf(buf, "\tstart = %" B_PRIdBIGTIME ", offset = %" B_PRIdBIGTIME "\n",
sprintf(buf, "\tstart = %" B_PRIdBIGTIME ", offset = %" B_PRIdBIGTIME ", size = %zu/%zu, "
PRINT(("LoggingConsumer::Start(%" B_PRIdBIGTIME "): now %" B_PRIdBIGTIME "\n",
printf("Setting producer run mode latency to %" B_PRIdBIGTIME "\n", latency);
"\thowLate == %" B_PRIdBIGTIME "\n"
"\twhen == %" B_PRIdBIGTIME "\n", howLate, tpWhen));
PRINT(("\tprocessing latency = %" B_PRIdBIGTIME "\n", m_processingLatency));
PRINT(("\treturning %" B_PRIdBIGTIME "\n", *outLatency));
B_PRIdBIGTIME ")\n", status, tpWhen));
PRINT(("\tdownstream latency = %" B_PRIdBIGTIME "\n", m_downstreamLatency));
PRINT(("\treturning %" B_PRIdBIGTIME "\n", *outLatency));
" start_time: %" B_PRIdBIGTIME ", current: %" B_PRIdBIGTIME ", "
"latency: %" B_PRIdBIGTIME "\n", buffer->Header()->start_time,
") (perf. time %" B_PRIdBIGTIME ")\n", fFrame,
printf("seeked by time: %" B_PRIdBIGTIME " -> %" B_PRIdBIGTIME
"time: %" B_PRIdBIGTIME "\n", intervalStartTime);
B_PRIdBIGTIME " - %" B_PRIdBIGTIME ")\n",
printf("Event::Execute() - %" B_PRIdBIGTIME "\n", fTime);
fprintf(gOptions.output, " tick interval: %" B_PRIdBIGTIME " us\n",
printf("%" B_PRIdBIGTIME "\n", system_time());
printf("\t\tport %" B_PRId32 ", latency %" B_PRIdBIGTIME "\n",
printf("\t\tport %" B_PRId32 ", latency %" B_PRIdBIGTIME "\n",
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] ", \
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] %s" prefix, \
__out(DEBUG_APP ": [%" B_PRIdBIGTIME ": %5" B_PRId32 "] %s:%d: ", \
TRACE("arch_timer_set_hardware_timer: timeout %" B_PRIdBIGTIME "\n", timeout);
TRACE("arch_smp_set_apic_timer: config 0x%" B_PRIx32 ", timeout %" B_PRIdBIGTIME
out.Print(", timeout: %" B_PRIdBIGTIME, fTimeout);
out.Print(", timeout: %" B_PRIdBIGTIME, fTimeout);
kprintf(" total: %" B_PRIdBIGTIME " us\n", totalRunTime);
kprintf(" min: %" B_PRIdBIGTIME " us\n", minRunTime);
kprintf(" max: %" B_PRIdBIGTIME " us\n", maxRunTime);
kprintf(" total #: %" B_PRIdBIGTIME "\n", latencies);
kprintf(" total: %" B_PRIdBIGTIME " us\n", totalLatency);
kprintf(" min: %" B_PRIdBIGTIME " us\n", minLatency);
kprintf(" max: %" B_PRIdBIGTIME " us\n", maxLatency);
kprintf(" max: %" B_PRIdBIGTIME " us (at tracing entry %" B_PRId32
kprintf(" total: %" B_PRIdBIGTIME " us\n", totalRerunTime);
kprintf(" min: %" B_PRIdBIGTIME " us\n", minRerunTime);
kprintf(" max: %" B_PRIdBIGTIME " us (at tracing entry %" B_PRId32
kprintf(" total wait time: %" B_PRIdBIGTIME "\n", lock->total_wait);
kprintf(" total held time: %" B_PRIdBIGTIME "\n", lock->total_held);
kprintf(" last acquired at: %" B_PRIdBIGTIME "\n", lock->last_acquired);
panic("spinlock %p was held for %" B_PRIdBIGTIME " usecs (%d allowed)\n",
"%" B_PRIdBIGTIME, timeout);
TRACE(("timer_interrupt: time %" B_PRIdBIGTIME ", cpu %" B_PRId32 "\n",
printf("Mouse DOWN !!! %" B_PRIdBIGTIME "\n", system_time());
printf("Mouse UP !!! %" B_PRIdBIGTIME "\n", system_time());
printf("B_MOUSE_MOVED: %" B_PRIdBIGTIME "\n", when);
printf("B_MOUSE_UP: %" B_PRIdBIGTIME "\n", when);
printf("B_MOUSE_DOWN: %" B_PRIdBIGTIME "\n", when);
printf("completed %" B_PRIuSIZE " operations in %" B_PRIdBIGTIME " usec\n",