{"action":"created","issue":{"url":"https://api.github.com/repos/tensorflow/tensorflow/issues/113","labels_url":"https://api.github.com/repos/tensorflow/tensorflow/issues/113/labels{/name}","comments_url":"https://api.github.com/repos/tensorflow/tensorflow/issues/113/comments","events_url":"https://api.github.com/repos/tensorflow/tensorflow/issues/113/events","html_url":"https://github.com/tensorflow/tensorflow/pull/113","id":116243219,"number":113,"title":"AlexNet with FC layers: backward is very slow?","user":{"login":"jeffdonahue","id":965190,"avatar_url":"https://avatars.githubusercontent.com/u/965190?v=3","gravatar_id":"","url":"https://api.github.com/users/jeffdonahue","html_url":"https://github.com/jeffdonahue","followers_url":"https://api.github.com/users/jeffdonahue/followers","following_url":"https://api.github.com/users/jeffdonahue/following{/other_user}","gists_url":"https://api.github.com/users/jeffdonahue/gists{/gist_id}","starred_url":"https://api.github.com/users/jeffdonahue/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/jeffdonahue/subscriptions","organizations_url":"https://api.github.com/users/jeffdonahue/orgs","repos_url":"https://api.github.com/users/jeffdonahue/repos","events_url":"https://api.github.com/users/jeffdonahue/events{/privacy}","received_events_url":"https://api.github.com/users/jeffdonahue/received_events","type":"User","site_admin":false},"labels":[],"state":"closed","locked":false,"assignee":null,"milestone":null,"comments":7,"created_at":"2015-11-11T01:38:25Z","updated_at":"2015-11-11T21:07:47Z","closed_at":"2015-11-11T20:54:19Z","pull_request":{"url":"https://api.github.com/repos/tensorflow/tensorflow/pulls/113","html_url":"https://github.com/tensorflow/tensorflow/pull/113","diff_url":"https://github.com/tensorflow/tensorflow/pull/113.diff","patch_url":"https://github.com/tensorflow/tensorflow/pull/113.patch"},"body":"(I know PRs are not the way to contribute to TensorFlow -- I'm just posting this for discussion, though I'm happy to submit this patch via the official means if desired.)\r\n\r\nI modified `alexnet_benchmark.py` to compute activations for the fully-connected layers (fc6-fc8) where the original only computes through `pool5`.  Using a Titan X with the original code that only goes through `pool5`, I see roughly the expected result:\r\n\r\n```\r\n2015-11-10 16:29:54.760793: step 10, duration = 0.098\r\n2015-11-10 16:29:55.746638: step 20, duration = 0.099\r\n2015-11-10 16:29:56.734163: step 30, duration = 0.099\r\n2015-11-10 16:29:57.720769: step 40, duration = 0.098\r\n2015-11-10 16:29:58.708402: step 50, duration = 0.099\r\n2015-11-10 16:29:59.697522: step 60, duration = 0.100\r\n2015-11-10 16:30:00.687530: step 70, duration = 0.099\r\n2015-11-10 16:30:01.677052: step 80, duration = 0.099\r\n2015-11-10 16:30:02.669677: step 90, duration = 0.099\r\n2015-11-10 16:30:03.563315: Forward across 100 steps, 0.098 +/- 0.010 sec / batch\r\n2015-11-10 16:30:10.385117: step 10, duration = 0.321\r\n2015-11-10 16:30:13.613230: step 20, duration = 0.322\r\n2015-11-10 16:30:16.840772: step 30, duration = 0.322\r\n2015-11-10 16:30:20.068794: step 40, duration = 0.322\r\n2015-11-10 16:30:23.308556: step 50, duration = 0.326\r\n2015-11-10 16:30:26.558616: step 60, duration = 0.323\r\n2015-11-10 16:30:30.260454: step 70, duration = 0.325\r\n2015-11-10 16:30:33.939707: step 80, duration = 0.324\r\n2015-11-10 16:30:37.797578: step 90, duration = 0.326\r\n2015-11-10 16:30:41.159575: Forward-backward across 100 steps, 0.340 +/- 0.052 sec / batch\r\n```\r\n\r\nWith this modified version, I get expected computation speed for the forward-only version (only epsilon longer than the pool5 version), but very slow speeds doing forward-backward (stopped after 60 iterations due to slowness):\r\n\r\n```\r\n2015-11-10 15:54:39.231156: step 10, duration = 0.101\r\n2015-11-10 15:54:40.235104: step 20, duration = 0.100\r\n2015-11-10 15:54:41.238807: step 30, duration = 0.100\r\n2015-11-10 15:54:42.241662: step 40, duration = 0.100\r\n2015-11-10 15:54:43.245950: step 50, duration = 0.100\r\n2015-11-10 15:54:44.251555: step 60, duration = 0.100\r\n2015-11-10 15:54:45.255560: step 70, duration = 0.100\r\n2015-11-10 15:54:46.260286: step 80, duration = 0.101\r\n2015-11-10 15:54:47.268687: step 90, duration = 0.101\r\n2015-11-10 15:54:48.172288: Forward across 100 steps, 0.099 +/- 0.010 sec / batch\r\n2015-11-10 15:55:30.047371: step 10, duration = 13.337\r\n2015-11-10 15:58:34.855597: step 20, duration = 11.968\r\n2015-11-10 16:01:40.070674: step 30, duration = 19.707\r\n2015-11-10 16:04:30.698742: step 40, duration = 13.459\r\n2015-11-10 16:07:15.900770: step 50, duration = 20.028\r\n2015-11-10 16:10:11.997452: step 60, duration = 12.357\r\n^C^C^CTraceback (most recent call last):\r\n```\r\n\r\nDuring the forward-backward part of the benchmark, looking at GPU utilization using `nvidia-smi` while running this shows 0% utilization most of the time.\r\n\r\nFor reference, I ran more or less the equivalent timing on the same GPU using out-of-the-box Caffe (*no* CuDNN) using [this prototxt](https://gist.github.com/jeffdonahue/9193b3c88e4262128fe8), and see Forward-Backward times of ~413 ms.  (And for the record the comparison is still a little unfair to Caffe as `caffe time`, unlike `caffe train`, computes all gradients, including w.r.t. the input image.)\r\n\r\n```\r\n$ caffe time -model alexnet_dummydata_nolrn.prototxt -gpu 0\r\n[...]\r\nI1110 16:37:19.770344  6275 caffe.cpp:366] Average Forward pass: 176.546 ms.\r\nI1110 16:37:19.770350  6275 caffe.cpp:368] Average Backward pass: 237.147 ms.\r\nI1110 16:37:19.770356  6275 caffe.cpp:370] Average Forward-Backward: 413.773 ms.\r\n```\r\n\r\nPlease let me know if anyone has any idea what might be going on, or if something is wrong with my implementation (which I wouldn't doubt!).  Thanks!"},"comment":{"url":"https://api.github.com/repos/tensorflow/tensorflow/issues/comments/155911086","html_url":"https://github.com/tensorflow/tensorflow/pull/113#issuecomment-155911086","issue_url":"https://api.github.com/repos/tensorflow/tensorflow/issues/113","id":155911086,"user":{"login":"Yangqing","id":551151,"avatar_url":"https://avatars.githubusercontent.com/u/551151?v=3","gravatar_id":"","url":"https://api.github.com/users/Yangqing","html_url":"https://github.com/Yangqing","followers_url":"https://api.github.com/users/Yangqing/followers","following_url":"https://api.github.com/users/Yangqing/following{/other_user}","gists_url":"https://api.github.com/users/Yangqing/gists{/gist_id}","starred_url":"https://api.github.com/users/Yangqing/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/Yangqing/subscriptions","organizations_url":"https://api.github.com/users/Yangqing/orgs","repos_url":"https://api.github.com/users/Yangqing/repos","events_url":"https://api.github.com/users/Yangqing/events{/privacy}","received_events_url":"https://api.github.com/users/Yangqing/received_events","type":"User","site_admin":false},"created_at":"2015-11-11T21:07:47Z","updated_at":"2015-11-11T21:07:47Z","body":"Yeah, I was surprised too, although with a follow-up discussion it seems that the control flow was needed there as well. Sent a fix to Soumith for that earlier today.\r\n\r\nThanks Jeff for initiating the investigation! I really appreciate it."}}