From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([208.118.235.92]:40315) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1Se3nD-0000Wb-BU for qemu-devel@nongnu.org; Mon, 11 Jun 2012 08:32:29 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1Se3n4-00062t-FG for qemu-devel@nongnu.org; Mon, 11 Jun 2012 08:32:22 -0400 Received: from e28smtp01.in.ibm.com ([122.248.162.1]:38392) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1Se3n3-00061b-DY for qemu-devel@nongnu.org; Mon, 11 Jun 2012 08:32:14 -0400 Received: from /spool/local by e28smtp01.in.ibm.com with IBM ESMTP SMTP Gateway: Authorized Use Only! Violators will be prosecuted for from ; Mon, 11 Jun 2012 18:02:05 +0530 Received: from d28av03.in.ibm.com (d28av03.in.ibm.com [9.184.220.65]) by d28relay03.in.ibm.com (8.13.8/8.13.8/NCO v10.0) with ESMTP id q5BCW0FV14090496 for ; Mon, 11 Jun 2012 18:02:03 +0530 Received: from d28av03.in.ibm.com (loopback [127.0.0.1]) by d28av03.in.ibm.com (8.14.4/8.13.1/NCO v10.0 AVout) with ESMTP id q5BI1Gd6026982 for ; Tue, 12 Jun 2012 04:01:17 +1000 Message-ID: <4FD5E53E.7020505@linux.vnet.ibm.com> Date: Mon, 11 Jun 2012 18:01:58 +0530 From: Harsh Bora MIME-Version: 1.0 References: <1337853032-32590-1-git-send-email-harsh@linux.vnet.ibm.com> <1337853032-32590-3-git-send-email-harsh@linux.vnet.ibm.com> In-Reply-To: Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Subject: Re: [Qemu-devel] [PATCH v2 2/3] Simpletrace v2: Add support for multiple args, strings. List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Stefan Hajnoczi Cc: aneesh.kumar@linux.vnet.ibm.com, qemu-devel@nongnu.org, stefanha@linux.vnet.ibm.com On 06/07/2012 08:02 PM, Stefan Hajnoczi wrote: > On Thu, May 24, 2012 at 10:50 AM, Harsh Prateek Bora > wrote: >> A newer tracelog format which gets rid of fixed size trace records and >> therefore allows to trace multiple arguments as well as strings in trace >> events. >> >> Sample trace: >> v9fs_version 0.000 tag=0xffff id=0x64 msize=0x2000 version=9P2000.L >> v9fs_version_return 6.705 tag=0xffff id=0x64 msize=0x2000 version=9P2000.L >> v9fs_attach 174.467 tag=0x1 id=0x68 fid=0x0 afid=0xffffffffffffffff >> uname=nobody aname= >> v9fs_attach_return 4720.454 tag=0x1 id=0x68 type=0xffffffffffffff80 >> version=0x4f2a4dd0 path=0x220ea6 >> >> Signed-off-by: Harsh Prateek Bora >> --- >> scripts/tracetool/backend/simple.py | 84 ++++++++++--- >> trace/simple.c | 229 ++++++++++++++++++++++------------- >> trace/simple.h | 38 +++++- >> 3 files changed, 240 insertions(+), 111 deletions(-) > > Sorry for the delay. Mostly easy to fix comments, some care still > needed to avoid race conditions and use memory barriers in the right > places. > Hi Stefan, Thanks for reviewing, I have some questions below: >> @@ -75,16 +96,22 @@ static char *trace_file_name = NULL; >> * >> * Returns false if the record is not valid. >> */ >> -static bool get_trace_record(unsigned int idx, TraceRecord *record) >> +static bool get_trace_record(unsigned int idx, TraceRecord **recordptr) >> { >> - if (!(trace_buf[idx].event& TRACE_RECORD_VALID)) { >> + uint8_t temp_rec[ST_REC_HDR_LEN]; >> + TraceRecord *record = (TraceRecord *) temp_rec; >> + read_from_buffer(idx, temp_rec, ST_REC_HDR_LEN); >> + >> + if (!(record->event& TRACE_RECORD_VALID)) { >> return false; >> } >> >> __sync_synchronize(); /* read memory barrier before accessing record */ > > The need for the memory barrier is no longer clear. Previously we > were directly accessing the trace ring buffer, and therefore needed to > ensure fields were settled before accessing them. Now we use > read_from_buffer() which copies the data into our temporary struct on > the stack. > > I think the best way of doing it is to read the event field first in a > separate step, then do the read memory barrier, and then read the rest > of the record. This ensures that the event field is at least as "old" > as the other fields we read. Currently, it does a two step read: read header (which includes event field and length of record as well) sync read rest of record (using length from header) Are you suggesting this: read event field only sync (if event valid) read header (for length) sync read rest of record (using length) or read event field only sync (if event valid) read header (for length) read rest of record As we cant read the whole record in one step without knowing its length. > >> >> - *record = trace_buf[idx]; >> - record->event&= ~TRACE_RECORD_VALID; >> + *recordptr = g_malloc(record->length); >> + /* make a copy of record to avoid being overwritten */ >> + read_from_buffer(idx, (uint8_t *)*recordptr, record->length); >> + (*recordptr)->event&= ~TRACE_RECORD_VALID; >> return true; >> } >> [....] >> >> -void trace3(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3) >> +int trace_alloc_record(TraceBufferRecord *rec, TraceEventID event, uint32_t datasize) >> { >> - trace(event, x1, x2, x3, 0, 0, 0); >> + unsigned int idx, rec_off; >> + uint32_t rec_len = ST_REC_HDR_LEN + datasize; >> + uint64_t timestamp_ns = get_clock(); >> + >> + if ((rec_len + trace_idx - writeout_idx)> TRACE_BUF_LEN) { >> + /* Trace Buffer Full, Event dropped ! */ >> + dropped_events++; >> + return 1; > > -ENOSPC? A negative errno is clearer than 0 - success, 1 - failure. > >> + } >> + idx = g_atomic_int_exchange_and_add((gint *)&trace_idx, rec_len) % TRACE_BUF_LEN; > > How does this deal with the race condition of two or more threads > running trace_alloc_record() concurrently when the buffer reaches max > size? I think two or more threads could think they have enough space > because trace_idx hasn't been updated yet between the buffer length > check and the atomic update. Are you suggesting to use locking here ? I couldnt find a test-and-set alternative in glib2. Does qemu have access to any such interface ? > >> + >> + /* To check later if threshold crossed */ >> + rec->next_tbuf_idx = trace_idx % TRACE_BUF_LEN; >> + >> + rec_off = idx; >> + write_to_buffer(rec_off, (uint8_t*)&event, sizeof(event)); >> + rec_off += sizeof(event); >> + write_to_buffer(rec_off, (uint8_t*)×tamp_ns, sizeof(timestamp_ns)); >> + rec_off += sizeof(timestamp_ns); >> + write_to_buffer(rec_off, (uint8_t*)&rec_len, sizeof(rec_len)); >> + rec_off += sizeof(rec_len); > > This suggests a pattern where write_to_buffer() returns the new index: > > rec_off = write_to_buffer(rec_off, (uint8_t*)&event, sizeof(event)); > > That way you don't need to do the separate sizeof() additions. > >> + >> + rec->tbuf_idx = idx; >> + rec->rec_off = (idx + ST_REC_HDR_LEN) % TRACE_BUF_LEN; >> + return 0; >> } >> >> -void trace4(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4) >> +static void read_from_buffer(unsigned int idx, uint8_t *dataptr, uint32_t size) > > size_t is the type to use for memory size units. > [...] >> +void trace_record_finish(TraceBufferRecord *rec); >> +uint32_t safe_strlen(const char* str); > > Given that safe_strlen() is only used once and a generic utility (not > specific to the simple trace backend), I suggest dropping it an just > open coding the tristate operator: s ? strlen(s) : 0. > safe_strlen is used multiple times in auto-generated code by tracetool in expression for calculating the sum of size of trace arguments which as of now looks like: 8 + 8 + 4 + safe_strlen(str1) + 8 + 4 + safe_strlen(str2) ... for tracing events with string arguments. For trace events with multiple strings, this expression is more readable as compared to having an expression with tristate operator like this: 8 + 8 + 4 + (str1 ? strlen(str1) : 0) + 8 + 4 + (str2 ? strlen(str2) : 0) ... I agree that its a generic function and need not be placed in tracing code, let me know the right place where to put it if you think its worth keeping it. regards, Harsh > Stefan >