Tracing program with PID 4213 and its children ... NOTE: Output of traced programs is asynchron wrt. the output of this script! TIMESTAMP PPID PID CID ELAPS T FILE:LINE -- NAME My PID: 4213 2015507837934646 4212 4213 1 0us b hello.sh:2 -> echo 2015507838009433 4212 4213 1 21us b hello.sh:- <- echo 2015507838041109 4212 4213 1 31us b hello.sh:3 -> echo 'My PID: 4213' 2015507838080222 4212 4213 1 6us b hello.sh:- <- echo 2015507842119560 4212 4213 0 4ms c hello.sh:4 -> sleep '10' create ppid=4213 pid=4215 sleep Hello World! Hello World! Two Hello World! Two Three Hello World! Two Three Four Hello World! Two Three Four Five 2015517858936671 4212 4213 0 10.0s c hello.sh:- <- sleep 2015517859028009 4212 4213 0 91us b hello.sh:10 -> echo 'Hello World!' 2015517859129542 4212 4213 0 29us b hello.sh:- <- echo 2015517859170015 4212 4213 0 40us b hello.sh:11 -> echo 'Hello World!' 'Two' 2015517859214719 4212 4213 0 7us b hello.sh:- <- echo 2015517859237418 4212 4213 0 22us b hello.sh:12 -> echo 'Hello World!' 'Two' 'Three' 2015517859286459 4212 4213 0 8us b hello.sh:- <- echo 2015517859310193 4212 4213 0 23us b hello.sh:13 -> echo 'Hello World!' 'Two' 'Three' 'Four' 2015517859361684 4212 4213 0 5us b hello.sh:- <- echo 2015517859391818 4212 4213 0 30us b hello.sh:14 -> echo 'Hello World!' 'Two' 'Three' 'Four' 'Five' 2015517859449853 4212 4213 0 5us b hello.sh:- <- echo 2015517862639802 4213 4216 1 0us f hello.sh:1 -> bla 2015517862722303 4213 4216 1 15us b hello.sh:7 -> echo 'bla' 2015517862815737 4213 4216 1 25us b hello.sh:- <- echo 2015517862847391 4213 4216 1 31us f hello.sh:- <- bla Hello World! bla Two Three Four Five 2015517863481362 4212 4213 1 4ms s hello.sh:1 -> PID:4216 2015517863528393 4212 4213 1 4us s hello.sh:- <- PID:4216 2015517863625964 4212 4213 1 97us b hello.sh:15 -> echo 'Hello World!' 'bla' 'Two' 'Three' 'Four' 'Five' 2015517863734551 4212 4213 1 19us b hello.sh:- <- echo 2015517866562692 4212 4213 1 2ms c hello.sh:16 -> sleep '1' create ppid=4213 pid=4217 sleep 2015518884686110 4212 4213 1 1.0s c hello.sh:- <- sleep 2015518889995373 4212 4213 0 5ms s hello.sh:17 -> PID:4218 create ppid=4218 pid=4219 cat 2015518891375705 4213 4218 1 0us s hello.sh:17 -> PID:4219 2015518891425359 4213 4218 1 6us s hello.sh:- <- PID:4219 create ppid=4218 pid=4220 wc 2015518894419147 4213 4218 1 2ms s hello.sh:17 -> PID:4220 2015518894469551 4213 4218 1 6us s hello.sh:- <- PID:4220 create ppid=4213 pid=4218 awk 28 lines 2015518904835276 4212 4213 0 14ms s hello.sh:- <- PID:4218 create ppid=4213 pid=4221 sleep 2015518909427817 4212 4213 1 4ms c hello.sh:18 -> sleep '1' 2015519925852708 4212 4213 0 1.0s c hello.sh:- <- sleep 2015519925967916 4212 4213 0 115us b hello.sh:19 -> [ '-z' '' ']' 2015519926065382 4212 4213 0 10us b hello.sh:- <- [ create ppid=4213 pid=4223 expr 2015519930933632 4212 4213 1 4ms s hello.sh:1 -> PID:4223 2015519930987406 4212 4213 1 6us s hello.sh:- <- PID:4223 2015519932713231 4212 4213 1 1ms b hello.sh:25 -> [ '4' '-gt' '0' ']' 2015519932833114 4212 4213 1 25us b hello.sh:- <- [ 2015519935852653 4212 4213 1 3ms c hello.sh:26 -> ls '-d' '.' create ppid=4213 pid=4224 ls . 2015519938452709 4212 4213 1 2ms c hello.sh:- <- ls 2015519944748705 4212 4213 1 6ms c hello.sh:27 -> ./hello.sh '4' create ppid=4213 pid=4225 hello.sh My PID: 4225 2015519950137124 4213 4225 0 0us b hello.sh:2 -> echo 2015519950236923 4213 4225 0 31us b hello.sh:- <- echo 2015519950273866 4213 4225 0 36us b hello.sh:3 -> echo 'My PID: 4225' 2015519950312006 4213 4225 0 5us b hello.sh:- <- echo 2015519953496423 4213 4225 0 3ms c hello.sh:4 -> sleep '10' create ppid=4225 pid=4226 sleep Hello World! Hello World! Two Hello World! Two Three Hello World! Two Three Four Hello World! Two Three Four Five Hello World! bla Two Three Four Five 2015529970884275 4213 4225 0 10.0s c hello.sh:- <- sleep 2015529970961355 4213 4225 0 77us b hello.sh:10 -> echo 'Hello World!' 2015529971062190 4213 4225 0 28us b hello.sh:- <- echo 2015529971105263 4213 4225 0 43us b hello.sh:11 -> echo 'Hello World!' 'Two' 2015529971147981 4213 4225 0 5us b hello.sh:- <- echo 2015529971172884 4213 4225 0 24us b hello.sh:12 -> echo 'Hello World!' 'Two' 'Three' 2015529971219353 4213 4225 0 5us b hello.sh:- <- echo 2015529971243277 4213 4225 0 23us b hello.sh:13 -> echo 'Hello World!' 'Two' 'Three' 'Four' 2015529971296343 4213 4225 0 7us b hello.sh:- <- echo 2015529971324143 4213 4225 0 27us b hello.sh:14 -> echo 'Hello World!' 'Two' 'Three' 'Four' 'Five' 2015529971383780 4213 4225 0 7us b hello.sh:- <- echo 2015529974344414 4213 4225 0 2ms s hello.sh:1 -> PID:4228 2015529974394691 4213 4225 0 6us s hello.sh:- <- PID:4228 2015529974655243 4225 4228 1 0us f hello.sh:1 -> bla 2015529974741129 4225 4228 1 13us b hello.sh:7 -> echo 'bla' 2015529974836515 4225 4228 1 29us b hello.sh:- <- echo 2015529974869050 4225 4228 1 32us f hello.sh:- <- bla 2015529975507930 4213 4225 0 1ms b hello.sh:15 -> echo 'Hello World!' 'bla' 'Two' 'Three' 'Four' 'Five' 2015529975635499 4213 4225 0 24us b hello.sh:- <- echo 2015529978659500 4213 4225 0 3ms c hello.sh:16 -> sleep '1' create ppid=4225 pid=4229 sleep 2015530998915907 4213 4225 0 1.0s c hello.sh:- <- sleep 2015531002685125 4213 4225 0 3ms s hello.sh:17 -> PID:4230 28 lines create ppid=4230 pid=4231 cat 2015531006068656 4225 4230 1 0us s hello.sh:17 -> PID:4231 2015531006116855 4225 4230 1 4us s hello.sh:- <- PID:4231 create ppid=4230 pid=4232 wc create ppid=4225 pid=4230 awk 2015531017718909 4213 4225 0 14ms s hello.sh:- <- PID:4230 2015531009493821 4225 4230 1 3ms s hello.sh:17 -> PID:4232 2015531009544639 4225 4230 1 6us s hello.sh:- <- PID:4232 2015531021067144 4213 4225 0 3ms c hello.sh:18 -> sleep '1' create ppid=4225 pid=4233 sleep 2015532038800966 4213 4225 1 1.0s c hello.sh:- <- sleep 2015532038932364 4213 4225 1 131us b hello.sh:19 -> [ '-z' '4' ']' 2015532039027825 4213 4225 1 11us b hello.sh:- <- [ 2015532042654597 4213 4225 0 3ms s hello.sh:1 -> PID:4234 2015532042705307 4213 4225 0 6us s hello.sh:- <- PID:4234 create ppid=4225 pid=4234 expr 2015532045900083 4213 4225 0 3ms b hello.sh:25 -> [ '3' '-gt' '0' ']' 2015532046012084 4213 4225 0 31us b hello.sh:- <- [ 2015532049244424 4213 4225 0 3ms c hello.sh:26 -> ls '-d' '.' . 2015532052158117 4213 4225 0 2ms c hello.sh:- <- ls 2015532056359899 4213 4225 0 4ms c hello.sh:27 -> ./hello.sh '3' create ppid=4225 pid=4235 ls My PID: 4236 create ppid=4225 pid=4236 hello.sh 2015532061589521 4225 4236 0 0us b hello.sh:2 -> echo 2015532061669492 4225 4236 0 22us b hello.sh:- <- echo 2015532061706344 4225 4236 0 36us b hello.sh:3 -> echo 'My PID: 4236' 2015532061744843 4225 4236 0 5us b hello.sh:- <- echo 2015532065598524 4225 4236 0 3ms c hello.sh:4 -> sleep '10' create ppid=4236 pid=4237 sleep Hello World! Hello World! Two Hello World! Two Three Hello World! Two Three Four Hello World! Two Three Four Five 2015542085442394 4225 4236 0 10.0s c hello.sh:- <- sleep 2015542085521759 4225 4236 0 79us b hello.sh:10 -> echo 'Hello World!' 2015542085621547 4225 4236 0 28us b hello.sh:- <- echo 2015542085663412 4225 4236 0 41us b hello.sh:11 -> echo 'Hello World!' 'Two' 2015542085705679 4225 4236 0 5us b hello.sh:- <- echo 2015542085730490 4225 4236 0 24us b hello.sh:12 -> echo 'Hello World!' 'Two' 'Three' 2015542085776892 4225 4236 0 5us b hello.sh:- <- echo 2015542085800829 4225 4236 0 23us b hello.sh:13 -> echo 'Hello World!' 'Two' 'Three' 'Four' 2015542085854080 4225 4236 0 7us b hello.sh:- <- echo 2015542085881766 4225 4236 0 27us b hello.sh:14 -> echo 'Hello World!' 'Two' 'Three' 'Four' 'Five' 2015542085941680 4225 4236 0 8us b hello.sh:- <- echo 2015542089682524 4236 4238 1 0us f hello.sh:1 -> bla Hello World! bla Two Three Four Five 2015542089359038 4225 4236 0 3ms s hello.sh:1 -> PID:4238 2015542089408818 4225 4236 0 6us s hello.sh:- <- PID:4238 2015542089767056 4236 4238 1 15us b hello.sh:7 -> echo 'bla' 2015542089863069 4236 4238 1 29us b hello.sh:- <- echo 2015542089893452 4236 4238 1 30us f hello.sh:- <- bla 2015542090564868 4225 4236 0 1ms b hello.sh:15 -> echo 'Hello World!' 'bla' 'Two' 'Three' 'Four' 'Five' 2015542090686650 4225 4236 0 16us b hello.sh:- <- echo 2015542094147865 4225 4236 0 3ms c hello.sh:16 -> sleep '1' create ppid=4236 pid=4239 sleep 2015543111504712 4225 4236 0 1.0s c hello.sh:- <- sleep 2015543115689106 4225 4236 0 4ms s hello.sh:17 -> PID:4240 2015543119453719 4236 4240 1 0us s hello.sh:17 -> PID:4241 2015543119503049 4236 4240 1 6us s hello.sh:- <- PID:4241 create ppid=4240 pid=4242 wc create ppid=4240 pid=4241 cat 2015543124134101 4236 4240 1 4ms s hello.sh:17 -> PID:4242 2015543124186214 4236 4240 1 6us s hello.sh:- <- PID:4242 create ppid=4236 pid=4240 awk 28 lines 2015543130843329 4225 4236 0 15ms s hello.sh:- <- PID:4240 2015543138471991 4225 4236 0 7ms c hello.sh:18 -> sleep '1' create ppid=4236 pid=4243 sleep 2015544156150291 4225 4236 0 1.0s c hello.sh:- <- sleep 2015544156261942 4225 4236 0 111us b hello.sh:19 -> [ '-z' '3' ']' 2015544156358301 4225 4236 0 10us b hello.sh:- <- [ 2015544160369992 4225 4236 0 4ms s hello.sh:1 -> PID:4244 2015544160420812 4225 4236 0 7us s hello.sh:- <- PID:4244 create ppid=4236 pid=4244 expr 2015544163706592 4225 4236 0 3ms b hello.sh:25 -> [ '2' '-gt' '0' ']' 2015544163828712 4225 4236 0 23us b hello.sh:- <- [ 2015544167451074 4225 4236 0 3ms c hello.sh:26 -> ls '-d' '.' create ppid=4236 pid=4245 ls . 2015544169778775 4225 4236 0 2ms c hello.sh:- <- ls 2015544176575856 4225 4236 0 6ms c hello.sh:27 -> ./hello.sh '2' My PID: 4246 create ppid=4236 pid=4246 hello.sh 2015544184096665 4236 4246 0 0us b hello.sh:2 -> echo 2015544184172743 4236 4246 0 20us b hello.sh:- <- echo 2015544184202291 4236 4246 0 29us b hello.sh:3 -> echo 'My PID: 4246' 2015544184242022 4236 4246 0 7us b hello.sh:- <- echo 2015544188287076 4236 4246 0 4ms c hello.sh:4 -> sleep '10' create ppid=4246 pid=4247 sleep Hello World! Hello World! Two Hello World! Two Three Hello World! Two Three Four Hello World! Two Three Four Five 2015554208311202 4236 4246 0 10.0s c hello.sh:- <- sleep 2015554208387839 4236 4246 0 76us b hello.sh:10 -> echo 'Hello World!' 2015554208489604 4236 4246 0 30us b hello.sh:- <- echo 2015554208530201 4236 4246 0 40us b hello.sh:11 -> echo 'Hello World!' 'Two' 2015554208574631 4236 4246 0 7us b hello.sh:- <- echo 2015554208597318 4236 4246 0 22us b hello.sh:12 -> echo 'Hello World!' 'Two' 'Three' 2015554208643623 4236 4246 0 5us b hello.sh:- <- echo 2015554208669556 4236 4246 0 25us b hello.sh:13 -> echo 'Hello World!' 'Two' 'Three' 'Four' 2015554208720559 4236 4246 0 5us b hello.sh:- <- echo 2015554208748206 4236 4246 0 27us b hello.sh:14 -> echo 'Hello World!' 'Two' 'Three' 'Four' 'Five' 2015554208807973 4236 4246 0 7us b hello.sh:- <- echo Hello World! bla Two Three Four Five 2015554212694694 4236 4246 0 3ms s hello.sh:1 -> PID:4248 2015554212745897 4236 4246 0 6us s hello.sh:- <- PID:4248 2015554213004747 4246 4248 1 0us f hello.sh:1 -> bla 2015554213086915 4246 4248 1 13us b hello.sh:7 -> echo 'bla' 2015554213183555 4246 4248 1 29us b hello.sh:- <- echo 2015554213213731 4246 4248 1 30us f hello.sh:- <- bla 2015554213877923 4236 4246 0 1ms b hello.sh:15 -> echo 'Hello World!' 'bla' 'Two' 'Three' 'Four' 'Five' 2015554214006847 4236 4246 0 17us b hello.sh:- <- echo 2015554217954369 4236 4246 0 3ms c hello.sh:16 -> sleep '1' create ppid=4246 pid=4249 sleep 2015555235954124 4236 4246 1 1.0s c hello.sh:- <- sleep 2015555240776131 4236 4246 0 4ms s hello.sh:17 -> PID:4250 28 lines create ppid=4250 pid=4251 cat 2015555245117872 4246 4250 1 0us s hello.sh:17 -> PID:4251 2015555245166705 4246 4250 1 6us s hello.sh:- <- PID:4251 create ppid=4250 pid=4252 wc 2015555256928038 4236 4246 0 16ms s hello.sh:- <- PID:4250 2015555261157895 4236 4246 0 4ms c hello.sh:18 -> sleep '1' 2015555249506490 4246 4250 1 4ms s hello.sh:17 -> PID:4252 2015555249557043 4246 4250 1 6us s hello.sh:- <- PID:4252 create ppid=4246 pid=4250 awk create ppid=4246 pid=4253 sleep 2015556278576281 4236 4246 0 1.0s c hello.sh:- <- sleep 2015556278683522 4236 4246 0 107us b hello.sh:19 -> [ '-z' '2' ']' 2015556278779841 4236 4246 0 11us b hello.sh:- <- [ . create ppid=4246 pid=4254 expr 2015556284911105 4236 4246 0 6ms s hello.sh:1 -> PID:4254 2015556284963365 4236 4246 0 4us s hello.sh:- <- PID:4254 2015556286814019 4236 4246 0 1ms b hello.sh:25 -> [ '1' '-gt' '0' ']' 2015556286938817 4236 4246 0 25us b hello.sh:- <- [ 2015556291297085 4236 4246 0 4ms c hello.sh:26 -> ls '-d' '.' create ppid=4246 pid=4255 ls 2015556295446348 4236 4246 0 4ms c hello.sh:- <- ls 2015556299759676 4236 4246 0 4ms c hello.sh:27 -> ./hello.sh '1' create ppid=4246 pid=4256 hello.sh My PID: 4256 2015556305659289 4246 4256 1 0us b hello.sh:2 -> echo 2015556305736396 4246 4256 1 21us b hello.sh:- <- echo 2015556305766485 4246 4256 1 30us b hello.sh:3 -> echo 'My PID: 4256' 2015556305810271 4246 4256 1 10us b hello.sh:- <- echo 2015556311555550 4246 4256 0 5ms c hello.sh:4 -> sleep '10' create ppid=4256 pid=4257 sleep Hello World! Hello World! Two Hello World! Two Three Hello World! Two Three Four 2015566329634785 4246 4256 1 10.0s c hello.sh:- <- sleep 2015566329719520 4246 4256 1 84us b hello.sh:10 -> echo 'Hello World!' Hello World! Two Three Four Five 2015566329822651 4246 4256 1 33us b hello.sh:- <- echo 2015566329865405 4246 4256 1 42us b hello.sh:11 -> echo 'Hello World!' 'Two' 2015566329908848 4246 4256 1 5us b hello.sh:- <- echo 2015566329932682 4246 4256 1 23us b hello.sh:12 -> echo 'Hello World!' 'Two' 'Three' 2015566329981594 4246 4256 1 7us b hello.sh:- <- echo 2015566330019518 4246 4256 1 37us b hello.sh:13 -> echo 'Hello World!' 'Two' 'Three' 'Four' 2015566330075480 4246 4256 1 9us b hello.sh:- <- echo 2015566330103895 4246 4256 1 28us b hello.sh:14 -> echo 'Hello World!' 'Two' 'Three' 'Four' 'Five' 2015566330180753 4246 4256 1 24us b hello.sh:- <- echo 2015566335023757 4256 4258 0 0us f hello.sh:1 -> bla 2015566334710195 4246 4256 1 4ms s hello.sh:1 -> PID:4258 2015566334760914 4246 4256 1 6us s hello.sh:- <- PID:4258 Hello World! bla Two Three Four Five 2015566335111769 4256 4258 0 16us b hello.sh:7 -> echo 'bla' 2015566335207232 4256 4258 0 26us b hello.sh:- <- echo 2015566335239876 4256 4258 0 32us f hello.sh:- <- bla 2015566335903457 4246 4256 1 1ms b hello.sh:15 -> echo 'Hello World!' 'bla' 'Two' 'Three' 'Four' 'Five' 2015566336023322 4246 4256 1 16us b hello.sh:- <- echo 2015566341520495 4246 4256 1 5ms c hello.sh:16 -> sleep '1' create ppid=4256 pid=4259 sleep 2015567359945384 4246 4256 0 1.0s c hello.sh:- <- sleep 2015567365585549 4246 4256 1 5ms s hello.sh:17 -> PID:4260 2015567370677659 4256 4260 0 0us s hello.sh:17 -> PID:4261 2015567370725906 4256 4260 0 4us s hello.sh:- <- PID:4261 create ppid=4260 pid=4261 cat 2015567375915152 4256 4260 0 5ms s hello.sh:17 -> PID:4262 2015567375964439 4256 4260 0 4us s hello.sh:- <- PID:4262 create ppid=4260 pid=4262 wc create ppid=4256 pid=4260 awk 28 lines 2015567383407115 4246 4256 0 17ms s hello.sh:- <- PID:4260 2015567389965794 4246 4256 0 6ms c hello.sh:18 -> sleep '1' create ppid=4256 pid=4263 sleep 2015568407728786 4246 4256 1 1.0s c hello.sh:- <- sleep 2015568407854896 4246 4256 1 126us b hello.sh:19 -> [ '-z' '1' ']' 2015568407950258 4246 4256 1 11us b hello.sh:- <- [ 2015568413444589 4246 4256 1 5ms s hello.sh:1 -> PID:4264 2015568413496223 4246 4256 1 6us s hello.sh:- <- PID:4264 create ppid=4256 pid=4264 expr 2015568416882193 4246 4256 1 3ms b hello.sh:25 -> [ '0' '-gt' '0' ']' 2015568417007666 4246 4256 1 28us b hello.sh:- <- [ 2015568417584520 4236 4246 0 12.1s c hello.sh:- <- ./hello.sh 2015568418250193 4225 4236 1 24.2s c hello.sh:- <- ./hello.sh 2015568418780774 4213 4225 0 36.4s c hello.sh:- <- ./hello.sh 2015568419312885 4212 4213 1 48.5s c hello.sh:- <- ./hello.sh Tracing done. (1.0m)