dump chrome: JSON parsing error about cpython trace json file

[Taeung]

Hi,

I found JSON parsing error like below on chrome://tracing when loading a json file dumped from cpython trace data. But I'm not sure it is a uftrace's problem. Can you check py_hello.json.zip ?

While importing:
SyntaxError: Unexpected token h in JSON at position 956
    at JSON.parse (<anonymous>)
    at new TraceEventImporter (chrome://tracing/tracing.js:4876:19)
    at Import.createImporter_ (chrome://tracing/tracing.js:1165:8)
    at addImportStage (chrome://tracing/tracing.js:1159:167)
    at Task.run (chrome://tracing/tracing.js:2207:95)
    at runAnother (chrome://tracing/tracing.js:2210:371)
    at runTask (chrome://tracing/tracing.js:2186:57)
    at processIdleWork (chrome://tracing/tracing.js:2191:116)
    at window.requestIdleCallback.timeout (chrome://tracing/tracing.js:2184:81)

I tested it like below: (recording, replaying and reporting is fine without any errors)

$ ./python --version
Python 3.6.2

$ uftrace record -D 4 -t 1ms ./python -c 'print("hello")'

$ uftrace dump --chrome > py_hello.json

$ uftrace info
# system information
# ==================
# program version     : uftrace v0.8-59-g7181
# recorded on         : Fri Oct 20 13:07:07 2017
# cmdline             : uftrace record -D 4 -t 1ms ./python -c print("hello") 
# cpu info            : Intel(R) Core(TM) i7-5500U CPU @ 2.40GHz
# number of cpus      : 4 / 4 (online / possible)
# memory info         : 0.0 / 7.4 GB (free / total)
# system load         : 0.36 / 0.31 / 0.36 (1 / 5 / 15 min)
# kernel version      : Linux 4.5.0-rc4+
# hostname            : taeung-ThinkPad-X1-Carbon-3rd
# distro              : "Ubuntu 16.04.3 LTS"
#
# process information
# ===================
# number of tasks     : 1
# task list           : 7290
# exe image           : /home/taeung/git/opensource/cpython/python
# exit status         : exited with code: 0
# elapsed time        : 0.068235585 sec
# cpu time            : 0.008 / 0.048 sec (sys / user)
# context switch      : 50 / 2 (voluntary / involuntary)
# max rss             : 9684 KB
# page fault          : 27 / 1247 (major / minor)
# disk iops           : 6512 / 16 (read / write)

( In addition, the Nmap case hasn't any problems testing chrome://tracing with dumped json file)

[namhyung]

It seems to be a problem of non-escaped double-quotation at the command-line. Your command line contains "hello" and it makes to fail to parse the JSON string.

{"traceEvents":[                                                                                                                                                                                         
{"ts":412484404469.064,"ph":"B","pid":7290,"name":"main"},                                                                                                                                               
...                                                                                                                                           
], "displayTimeUnit": "ns", "metadata": {                                                                                                                                                                
"command_line":"uftrace record -D 4 -t 1ms ./python -c print("hello") ",                                                                                                                                 
"recorded_time":"Fri Oct 20 13:07:07 2017"                   ^^^^^^^                                                                                                                                                        
} }

[Taeung]

Ah, understood !

@namhyung And a json file that contains kernel trace data can't be shown on chrome browser ? nmap_kern.json.zip

$ pwd
/home/taeung/git/opensource/nmap/uftrace.data.nmap_kern

$ uftrace info
# system information
# ==================
# program version     : uftrace v0.8-59-g7181
# recorded on         : Fri Oct 20 14:01:17 2017
# cmdline             : uftrace record -K 4 -t 10us -d uftrace.data.nmap_kern ./nmap nmap
...

$ uftrace dump --chrome > nmap_kern.json 
WARN: Some of function trace records are lost. (1 times shown)
WARN: The output json format may not show the correct view in chrome browser.

And then, I found similar JSON error on chrome browser like below:

While importing:
SyntaxError: Unexpected token , in JSON at position 1524111
    at JSON.parse (<anonymous>)
    at new TraceEventImporter (chrome://tracing/tracing.js:4876:19)
    at Import.createImporter_ (chrome://tracing/tracing.js:1165:8)
    at addImportStage (chrome://tracing/tracing.js:1159:167)
    at Task.run (chrome://tracing/tracing.js:2207:95)
    at runAnother (chrome://tracing/tracing.js:2210:371)
    at runTask (chrome://tracing/tracing.js:2186:57)
    at processIdleWork (chrome://tracing/tracing.js:2191:116)
    at window.requestIdleCallback.timeout (chrome://tracing/tracing.js:2184:81)

[namhyung]

No it should handle kernel functions AFAIK. Maybe because some kernel functions are lost? But I guess it should be able to parse the data anyway. Could you give me a link to the data?

[Taeung]

I removed the above trace data by my mistake, but I have other trace data that has same problem.

So I give it to you. uftrace.data.nmap_kern.zip

[Taeung]

@namhyung I checked that a json file that contains kernel trace data can be loaded on chrome browser.

$ uftrace record -K 5 -N smp_irq_work_interrupt@kernel -N syscall_trace_enter_phase1@kernel -N syscall_slow_exit_work@kernel -t 10us -d uftrace.data.nmap_kern

$ cd uftrace.data.nmap_kern

$ uftrace dump --chrome > nmap_kern.json

And then, it is shown on chrome browser without any problems.

[namhyung]

Attached patch should fix the first problem: escape-quoted-string-in-command-line.patch.txt

You need to run uftrace record again..

[namhyung]

@Taeung could you please check the above patch?

[namhyung]

Any update?

[Taeung]

Sorry really for late response..

I found the trivial warnings:

/home/taeung/git/uftrace/cmd-info.c: In function ‘fill_cmdline’:
/home/taeung/git/uftrace/cmd-info.c:271:2: warning: ignoring return value of ‘write’, declared with attribute warn_unused_result [-Wunused-result]
  write(fha->fd, "cmdline:", 8);
  ^
/home/taeung/git/uftrace/cmd-info.c:272:2: warning: ignoring return value of ‘write’, declared with attribute warn_unused_result [-Wunused-result]
  write(fha->fd, p, k+1);
  ^

In your patch

 14 diff --git a/cmd-info.c b/cmd-info.c                                      
 15 index bc4a19f..e0a5d4e 100644                                             
 16 --- a/cmd-info.c                                                          
 17 +++ b/cmd-info.c                                                          
 18 @@ -223,23 +223,55 @@ static int fill_cmdline(void *arg)
...
 72 +       write(fha->fd, "cmdline:", 8);                                    
 73 +       write(fha->fd, p, k+1);  

[Taeung]

Anyway it works !! @namhyung After I applied your patch, this problem is gone 👍

[namhyung]

Thanks, will fix.